InnoDB error

Hexweb · Feb 9, 2015

Hello all!

For one of my customers i'm hosting a VPS with a few wordpress news sites on it. (3 cores @ 2.4ghz, 4GB ram)

But now i'm having a issue with it. I can't seem to find out why it's happening.

This morning i fixed a few crashes by reducing the max amount of connections in Httpd (And turn off KeepAlive)

But mysqld is still crashing (2 a 3times per day) and restarting itself.

Can someone help with locating the issue and solving it?

Code:

Version: '5.5.31-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)150209 21:25:05 mysqld_safe Number of processes running now: 0
150209 21:25:06 mysqld_safe mysqld restarted
150209 21:25:08 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
150209 21:25:16 [Note] Plugin 'FEDERATED' is disabled.
150209 21:25:16 InnoDB: The InnoDB memory heap is disabled
150209 21:25:16 InnoDB: Mutexes and rw_locks use GCC atomic builtins
150209 21:25:16 InnoDB: Compressed tables use zlib 1.2.3
150209 21:25:16 InnoDB: Using Linux native AIO
150209 21:25:16 InnoDB: Initializing buffer pool, size = 512.0M
InnoDB: mmap(549453824 bytes) failed; errno 12
150209 21:25:16 InnoDB: Completed initialization of buffer pool
150209 21:25:16 InnoDB: Fatal error: cannot allocate memory for the buffer pool
150209 21:25:16 [ERROR] Plugin 'InnoDB' init function returned error.
150209 21:25:16 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
150209 21:25:16 [ERROR] Unknown/unsupported storage engine: InnoDB
150209 21:25:16 [ERROR] Aborting




150209 21:25:16 [Note] /usr/sbin/mysqld: Shutdown complete




150209 21:25:16 [Note] Plugin 'FEDERATED' is disabled.
150209 21:25:16 InnoDB: The InnoDB memory heap is disabled
150209 21:25:16 InnoDB: Mutexes and rw_locks use GCC atomic builtins
150209 21:25:16 InnoDB: Compressed tables use zlib 1.2.3
150209 21:25:16 InnoDB: Using Linux native AIO
150209 21:25:16 mysqld_safe mysqld from pid file /var/lib/mysql/HOSTNAME.pid ended
150209 21:25:16 InnoDB: Initializing buffer pool, size = 512.0M
InnoDB: mmap(549453824 bytes) failed; errno 12
150209 21:25:16 InnoDB: Completed initialization of buffer pool
150209 21:25:16 InnoDB: Fatal error: cannot allocate memory for the buffer pool
150209 21:25:16 [ERROR] Plugin 'InnoDB' init function returned error.
150209 21:25:16 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
150209 21:25:16 [ERROR] Unknown/unsupported storage engine: InnoDB
150209 21:25:16 [ERROR] Aborting




150209 21:25:16 [Note] /usr/sbin/mysqld: Shutdown complete




150209 21:25:16 mysqld_safe mysqld from pid file /var/lib/mysql/HOSTNAME.pid ended
150209 21:26:02 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
150209 21:26:02 [Note] Plugin 'FEDERATED' is disabled.
150209 21:26:02 InnoDB: The InnoDB memory heap is disabled
150209 21:26:02 InnoDB: Mutexes and rw_locks use GCC atomic builtins
150209 21:26:02 InnoDB: Compressed tables use zlib 1.2.3
150209 21:26:02 InnoDB: Using Linux native AIO
150209 21:26:02 InnoDB: Initializing buffer pool, size = 512.0M
150209 21:26:02 InnoDB: Completed initialization of buffer pool
150209 21:26:02 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
150209 21:26:02  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Last MySQL binlog file position 0 22857147, file name ./mysql-bin.000062
150209 21:26:03  InnoDB: Waiting for the background threads to start
150209 21:26:04 InnoDB: 5.5.31 started; log sequence number 5812358132
150209 21:26:04 [Note] Recovering after a crash using mysql-bin
150209 21:26:04 [Note] Starting crash recovery...
150209 21:26:04 [Note] Crash recovery finished.
150209 21:26:05 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
150209 21:26:05 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
150209 21:26:05 [Note] Server socket created on IP: '0.0.0.0'.
150209 21:26:05 [Note] Event Scheduler: Loaded 0 events
150209 21:26:05 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.31-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)

Thanks for the help!

zEitEr · Feb 10, 2015

Hello,

The server seems to not have enough RAM. You need either to lower innodb_buffer_pool_size or upgrade your server to have more RAM

Fatal error: cannot allocate memory for the buffer pool

Hexweb · Feb 10, 2015

Hey Alex,

It's weird that that's the error.

The innodb_buffer_pool_size is atm 512M
and the server has 4GB of ram.

When running Mysqltuner.pl it even says to increase the size.
[!!] InnoDB buffer pool / data size: 512.0M/612.5M

Current usage

Code:

top - 08:59:28 up 85 days, 17:46,  2 users,  load average: 0.98, 0.89, 1.38
Tasks: 170 total,   1 running, 169 sleeping,   0 stopped,   0 zombie
Cpu(s):  1.3%us,  1.0%sy,  0.0%ni, 97.7%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   3922548k total,  1612476k used,  2310072k free,    48868k buffers
Swap:  1047548k total,   117840k used,   929708k free,   420164k cached

And it's only at peak hours the mysql crashes (load springs up to 30???)

Code:

One Minute      - 80.9
Five Minutes    - 33.64
Fifteen Minutes - 13.26


top - 07:54:09 up 85 days, 16:40,  1 user,  load average: 85.97, 36.26, 14.33
Tasks: 324 total,   8 running, 316 sleeping,   0 stopped,   0 zombie
Cpu(s): 14.6%us,  1.4%sy,  0.0%ni, 81.7%id,  0.6%wa,  0.0%hi,  0.0%si,  1.7%st
Mem:   3922548k total,  3245112k used,   677436k free,     8832k buffers
Swap:  1047548k total,   682920k used,   364628k free,    92208k cached


 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
13220 id00004   20   0  382m  98m 1816 R 18.8  2.6   0:01.01 /usr/sbin/httpd -k start -DSSL
13229 id00004   20   0  374m  92m 2044 R 16.4  2.4   0:01.39 /usr/sbin/httpd -k start -DSSL
13230 id00004   20   0  383m 102m 2052 R 15.6  2.7   0:00.98 /usr/sbin/httpd -k start -DSSL  
13234 id00004   20   0  383m 101m 2052 R 15.6  2.6   0:01.32 /usr/sbin/httpd -k start -DSSL
13236 id00004   20   0  379m  97m 2052 R 14.8  2.5   0:01.02 /usr/sbin/httpd -k start -DSSL
13222 id00004   20   0  380m  98m 2052 R 11.7  2.6   0:01.11 /usr/sbin/httpd -k start -DSSL  
13223 id00004   20   0  381m  97m 1792 R 11.7  2.5   0:01.19 /usr/sbin/httpd -k start -DSSL  
13373 apache    20   0  286m  10m 5484 S  3.9  0.3   0:00.08 /usr/sbin/httpd -k start -DSSL  
1417 root      20   0  154m 8420  592 D  2.3  0.2   0:10.22 lfd - scanning log files        
13371 apache    20   0  286m 9708 4496 S  2.3  0.2   0:00.09 /usr/sbin/httpd -k start -DSSL  
13406 apache    20   0  286m 9624 4392 S  2.3  0.2   0:00.11 /usr/sbin/httpd -k start -DSSL  
13465 nobody    20   0 55196 3080 2464 S  2.3  0.1   0:00.03 /usr/local/directadmin/dataskq  
13211 apache    20   0  307m  34m 8092 S  1.6  0.9   0:01.16 /usr/sbin/httpd -k start -DSSL  
13369 apache    20   0  286m 9648 4404 S  1.6  0.2   0:00.12 /usr/sbin/httpd -k start -DSSL  
13394 apache    20   0  285m 9420 4368 S  1.6  0.2   0:00.06 /usr/sbin/httpd -k start -DSSL  
13400 apache    20   0  286m 9680 4472 S  1.6  0.2   0:00.07 /usr/sbin/httpd -k start -DSSL  
13458 root      20   0  153m 5272 4008 S  1.6  0.1   0:00.02 /usr/sbin/exim -Mc 1YL4i0-0003V0-Hv
  28 root      20   0     0    0    0 S  0.8  0.0  25:12.59 [kblockd/0]                           
  49 root      20   0     0    0    0 D  0.8  0.0   2:49.51 [kswapd0]                             
13455 root      20   0 15156 1344  868 R  0.8  0.0   0:00.01 /usr/bin/top -c -b -n 1         
   1 root      20   0 19232  216   48 S  0.0  0.0   0:20.95 /sbin/init                               
   2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [kthreadd]                               
   3 root      RT   0     0    0    0 S  0.0  0.0   0:39.53 [migration/0]

Hexweb · Feb 10, 2015

Update:

I also got the following message:

Code:

150209 10:23:56  InnoDB: Error: page 90908 log sequence number 4889461233
InnoDB: is in the future! Current system log sequence number 4787214190.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
InnoDB: for more information.

I've added
innodb_force_recovery = 1
To /etc/my.cnf
And exported my backups.

This error message has gone away!

Now the only thing left is the unregular crashes that are happening (See previous post)

zEitEr · Feb 10, 2015

And it's only at peak hours the mysql crashes (load springs up to 30???)

Try to lower it and see how it works during several days.

Check server-status and apache logs. Probably sites of user id00004 are under bot attack (spam, bruteforce) or are compromised (malware).

Hexweb · Feb 10, 2015

zEitEr said:
Try to lower it and see how it works during several days.

Check server-status and apache logs. Probably sites of user id00004 are under bot attack (spam, bruteforce) or are compromised (malware).

Yeah the websites are under attack that's why i already implemented alot of security measures to reduce the load. (It was normally on 5 or 6 and now on 0.80)

I'll try if that works. I've checked the server-status logs and found that the malware that was on the sites was back. It's a shame that Maldet won't find it

zEitEr · Feb 10, 2015

I've written that maldet when running with nightly cron checks by default only files modified during the latest 2 days. If a hacker uploaded an archive with files modified 3days and more before, maldet with nightly cron won't find it. That's why I recommend to run a full scan at least once per week:

Code:

maldet -b -a /home/?/domains/?/public_html/

And still it won't find all malicious files, but only those which are added into its malware bases.

Hexweb · Feb 10, 2015

Alex,Where did you change that?

Because this issue is on a different server.
I've installed maldet there with your howto and the same config as the server where you fixed it.

zEitEr · Feb 10, 2015

Marc,

it was mentioned here: http://forum.directadmin.com/showthread.php?t=45851&page=4&p=261563#post261563
I don't set it by default, as it might bring extra load to a server.

InnoDB error

Hexweb

Verified User

zEitEr

Super Moderator

Hexweb

Verified User

Hexweb

Verified User

zEitEr

Super Moderator

Hexweb

Verified User

zEitEr

Super Moderator

Hexweb

Verified User

zEitEr

Super Moderator