mariadb

MYSQL/MariaDB

Plugin 'InnoDB' registration as a STORAGE ENGINE failed

Stand der Seite : 13.02.2018 (Debian stretch)

root@i7-graf-st-dh:/# mysql --version
mysql  Ver 15.1 Distrib 10.1.26-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2
root@i7-graf-st-dh:/# uname -a
Linux i7-graf-st-dh 4.14.0-0.bpo.3-amd64 #1 SMP Debian 4.14.13-1~bpo9+1 (2018-01-14) x86_64 GNU/Linux

Da ich bei meiner Suche im Internet auch viel Seiten gefunden habe, die letztendlich zur Neuinstallation von mysql rieten, habe ich mich entschlossen, meine Lösung hier zu dokumentieren. Sie wird sicher nicht auf alle diese Probleme zutreffen, ist aber evtl eine Hilfe.

Aus dem Nichts konnte ich meine Datenbank nicht mehr öffnen.
Nach einem ps fax wurde mir klar, dass der Server nicht gestartet war.

 root@i7-graf-st-dh:~# ps fax | grep "mysql"
 9259 pts/0    S+     0:00              \_ grep --color=auto mysql
root@i7-graf-st-dh:~#

Die Fehlermeldung :

root@i7-graf-st-dh:~# systemctl start mysqld.service
Job for mariadb.service failed because the control process exited with error code.

Im Internet fand ich den Hinweis, innodb_force_recovery = 1 in die my.ini einzufügen.
Leider gab es diese Datei bei mir (SMP Debian 4.14.13-1~bpo9+1 (2018-01-14) x86_64 GNU/Linux ) nicht.
Ausserdem ist mittlerweile mysql durch Mariadb ersetzt worden.

Configfiles von MariaDB in /etc

root@i7-graf-st-dh:# ls -l  /etc/mysql
insgesamt 20
drwxr-xr-x 1 root root   44 Mai  8 13:09 conf.d
-rw------- 1 root root  277 Mai  9 14:01 debian.cnf
-rwxr-xr-x 1 root root 1509 Mär 28 22:59 debian-start
-rw-r--r-- 1 root root  869 Mär 28 22:59 mariadb.cnf
drwxr-xr-x 1 root root  128 Sep  6 15:20 mariadb.conf.d
lrwxrwxrwx 1 root root   24 Mai  8 13:09 my.cnf -> /etc/alternatives/my.cnf
-rw-r--r-- 1 root root  839 Jul  9  2016 my.cnf.fallback

root@i7-graf-st-dh:/etc/mysql# ll mariadb.conf.d/
insgesamt 16
-rw-r--r-- 1 root root  677 Mär 28 22:59 50-client.cnf
-rw-r--r-- 1 root root  336 Mär 28 22:59 50-mysql-clients.cnf
-rw-r--r-- 1 root root 1032 Mär 28 22:59 50-mysqld_safe.cnf
-rw-r--r-- 1 root root 3747 Sep  6 15:20 50-server.cnf

12.02.2018 mysql startet nicht

root@i7-graf-st-dh:/# systemctl start mysqld.service 
Job for mariadb.service failed because the control process exited with error code.
See "systemctl status mariadb.service" and "journalctl -xe" for details.


root@i7-graf-st-dh:~# systemctl status mariadb.service
● mariadb.service - MariaDB database server
   Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Mon 2018-02-12 10:45:32 CET; 1h 19min ago
  Process: 1975 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
  Process: 1888 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR |
  Process: 1886 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
  Process: 1885 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
 Main PID: 1975 (code=exited, status=1/FAILURE)
   Status: "MariaDB server is down"

Feb 12 10:45:31 i7-graf-st-dh systemd[1]: Starting MariaDB database server...
Feb 12 10:45:32 i7-graf-st-dh mysqld[1975]: 2018-02-12 10:45:32 139665958491008 [Note] /usr/sbin/mysqld (mysqld 10.1.26-MariaDB-0+deb9u1) starting as process 1975 ...
Feb 12 10:45:32 i7-graf-st-dh systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 10:45:32 i7-graf-st-dh systemd[1]: mariadb.service: Failed with result 'exit-code'.
Feb 12 10:45:32 i7-graf-st-dh systemd[1]: Failed to start MariaDB database server.


root@i7-graf-st-dh:~# my_print_defaults mysqld server mysqld-10.0 mariadb mariadb-10.0 client-server
root@i7-graf-st-dh:~# mysqld --print-defaults

In /var/log/mysql/error.log war ein Hinweis, dass der Bufferpool zu klein sei

2018-02-12 16:38:56 139965088985984 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.

2018-02-12 16:38:56 139965088985984 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2018-02-12 16:38:56 139965088985984 [Note] InnoDB: The InnoDB memory heap is disabled
2018-02-12 16:38:56 139965088985984 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-02-12 16:38:56 139965088985984 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-02-12 16:38:56 139965088985984 [Note] InnoDB: Compressed tables use zlib 1.2.8
2018-02-12 16:38:56 139965088985984 [Note] InnoDB: Using Linux native AIO
2018-02-12 16:38:56 139965088985984 [Note] InnoDB: Using SSE crc32 instructions
2018-02-12 16:38:56 139965088985984 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2018-02-12 16:38:56 139965088985984 [Note] InnoDB: Completed initialization of buffer pool
2018-02-12 16:38:56 139965088985984 [ERROR] InnoDB: Only one log file found.
2018-02-12 16:38:56 139965088985984 [ERROR] Plugin 'InnoDB' init function returned error.
2018-02-12 16:38:56 139965088985984 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2018-02-12 16:38:56 139965088985984 [Note] Plugin 'FEEDBACK' is disabled.
2018-02-12 16:38:56 139965088985984 [ERROR] Unknown/unsupported storage engine: InnoDB
2018-02-12 16:38:56 139965088985984 [ERROR] Aborting

Ok versuchen wir mal den Size zu erhöhen


root@i7-graf-st-dh:/etc/mysql/mariadb.conf.d# /etc/init.d/mysql start  --innodb_buffer_pool_size=128MB
[....] Starting mysql (via systemctl): mysql.serviceJob for mariadb.service failed because the control process exited with error code.
See "systemctl status mariadb.service" and "journalctl -xe" for details.

Hat nix gebracht



2018-02-12 16:55:57 139965870224256 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.

2018-02-12 16:55:57 139965870224256 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2018-02-12 16:55:57 139965870224256 [Note] InnoDB: The InnoDB memory heap is disabled
2018-02-12 16:55:57 139965870224256 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-02-12 16:55:57 139965870224256 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-02-12 16:55:57 139965870224256 [Note] InnoDB: Compressed tables use zlib 1.2.8
2018-02-12 16:55:57 139965870224256 [Note] InnoDB: Using Linux native AIO
2018-02-12 16:55:57 139965870224256 [Note] InnoDB: Using SSE crc32 instructions
2018-02-12 16:55:57 139965870224256 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2018-02-12 16:55:57 139965870224256 [Note] InnoDB: Completed initialization of buffer pool
2018-02-12 16:55:57 139965870224256 [ERROR] [ERROR] InnoDB: Only one log file found.
2018-02-12 16:55:57 139965870224256 [ERROR] Plugin 'InnoDB' init function returned error.
2018-02-12 16:55:57 139965870224256 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2018-02-12 16:55:57 139965870224256 [Note] Plugin 'FEEDBACK' is disabled.
2018-02-12 16:55:57 139965870224256 [ERROR] Unknown/unsupported storage engine: InnoDB
2018-02-12 16:55:57 139965870224256 [ERROR] Aborting

https://support.plesk.com/hc/en-us/articles/115000181713-Unable-to-start-mariadb-or-mysql-service-after-upgrading-it-Unknown-unsupported-storage-engine-InnoDB
https://www.linet-services.de/was-tun-wenns-brennt-innodb-corruption-und-recovery/

auch ein “innodb_force_recovery=4” in der Datei /etc/mysql/mariadb.conf.d/50-server.cnf bracht keinen Erfolg.

https://mariadb.com/kb/en/library/problem-while-starting-mariadb-server/
https://mariadb.com/kb/en/library/mysqlserver/
https://mariadb.com/kb/en/library/xtradb-and-innodb/
https://mariadb.com/kb/en/library/innodb-troubleshooting/
https://mariadb.com/kb/en/library/xtradbinnodb-buffer-pool/
https://mariadb.com/kb/en/library/xtradbinnodb-server-system-variables/#innodb_buffer_pool_size
Letztendlich war die entscheidende Zeile
2018-02-12 15:54:57 139965870224256 [ERROR] InnoDB: Only one log file found.

Vorhandene Datenbanken im Testsystem

 
 root@i7-graf-st-dh:/var/lib/mysql# ll
insgesamt 127020
-rw-rw---- 1 mysql mysql    16384 Feb 12 16:38 aria_log.00000001
-rw-rw---- 1 mysql mysql       52 Feb 12 16:38 aria_log_control
drwxrwx--- 1 mysql mysql      264 Jan  4 14:29 db54281x1817823
drwxrwx--- 1 mysql mysql      328 Nov  9 15:59 db54281x2353053
-rw-rw---- 1 mysql mysql 79691776 Feb  7 04:37 ibdata1
-rw-rw---- 1 mysql mysql 50331648 Feb  7 04:37 ib_logfile0
-rw-rw---- 1 mysql mysql        0 Nov  9 09:57 multi-master.info
drwx------ 1 mysql root      2600 Nov  8 21:26 mysql
drwx------ 1 mysql mysql       12 Nov  8 21:26 performance_schema
-rw-rw---- 1 mysql mysql    24576 Feb  7 04:37 tc.log
root@i7-graf-st-dh:/var/lib/mysql#

Ok, kicken/verschieben  wir also die Logfile ib_logfile0  raus.
root@i7-graf-st-dh:/var/lib/mysql#  mv ib_logfile0 old_ib_logfile0 

root@i7-graf-st-dh:/var/lib/mysql# service mysqld start
root@i7-graf-st-dh:/var/lib/mysql# ll
insgesamt 225324
-rw-rw---- 1 mysql mysql    16384 Feb 12 16:38 aria_log.00000001
-rw-rw---- 1 mysql mysql       52 Feb 12 16:38 aria_log_control
drwxrwx--- 1 mysql mysql      264 Jan  4 14:29 db54281x1817823
drwxrwx--- 1 mysql mysql      328 Nov  9 15:59 db54281x2353053
-rw-rw---- 1 mysql mysql 79691776 Feb 12 16:41 ibdata1
-rw-rw---- 1 mysql mysql 50331648 Feb 12 16:41 ib_logfile0
-rw-rw---- 1 mysql mysql 50331648 Feb 12 16:41 ib_logfile1
-rw-rw---- 1 mysql mysql        0 Nov  9 09:57 multi-master.info
drwx------ 1 mysql root      2600 Nov  8 21:26 mysql
-rw-rw---- 1 mysql mysql 50331648 Feb  7 04:37 old_ib_logfile0
drwx------ 1 mysql mysql       12 Nov  8 21:26 performance_schema
-rw-rw---- 1 mysql mysql    24576 Feb 12 16:41 tc.log
root@i7-graf-st-dh:/var/lib/mysql#

Nach dem Start sind wieder beide Logfile vorhanden. Server wieder anhalten. root@i7-graf-st-dh:/var/lib/mysql# service mysqld stop In der Datei /etc/mysql/mariadb.conf.d/50-server.cnf Werte für innodb_force_recovery in der Datei 50-server.cnf
siehe forcing-innodb-recovery.html

1 (SRV_FORCE_IGNORE_CORRUPT) Lets the server run even if it detects a corrupt page.
2 (SRV_FORCE_NO_BACKGROUND) Prevents the master thread and any purge threads from running.
3 (SRV_FORCE_NO_TRX_UNDO) Does not run transaction rollbacks after crash recovery.
4 (SRV_FORCE_NO_IBUF_MERGE) Prevents insert buffer merge operations. If they would cause a crash, does not do them. Does not calculate table statistics.
5 (SRV_FORCE_NO_UNDO_LOG_SCAN) Does not look at undo logs when starting the database: InnoDB treats even incomplete transactions as committed.This value can permanently corrupt data files.
6 (SRV_FORCE_NO_LOG_REDO) Does not do the redo log roll-forward in connection with recovery. This value can permanently corrupt data files.

# uncomment die innodb_force_recovery Zeile, wenn ein Recovery gemacht werden soll. # /etc/init.d/mysql stop # /etc/init.d/mysql start #innodb_force_recovery = 1 # danach # /etc/init.d/mysql stop # Zeile wieder zu Kommentar machen # /etc/init.d/mysql start

Fehlerursache

Die Fehlerursache war ein Blackout meinerseits vor dem Backup aller Datenbanken.
wenn wir uns die Logfiles in /var/log/ ansehen, dann folgt die Namensgebung dem Muster filename, filename.1, filename.2 ...
D.h Ältere Logfiles haben eine höhere Nummer.
Vor dem Backup habe ich ib_logfile1 gelöscht, um den Size des Backup zu reduzieren.
Leider ist aber ib_logfile1 keine Logfile in diesem Sinne und enthält die Logs der STORAGE ENGINE Beide Dateien müssen also vorhanden sein
Damit netstat vorhanden ist müssen die net-tools installiert sein

 netstat -lp        #  list Ports
 lsof -i -P		    # list open Files    -P   inhibits the conversion of port numbers to port names for network files.
 					#  Inhibiting the conversion may make lsof run a little faster. 
					#  It  is also useful when port name lookup is not working properly.