mariadb fails to start after update to v7.0.2

i_max · 12 March 2021 21:11

Hi there,

after updating to version 7.0.2 my mariadb server won’t start.

dietpi-services status

yields:

[FAILED] DietPi-Services | ● mariadb.service - MariaDB 10.3.27 database server
   Loaded: loaded (/lib/systemd/system/mariadb.service; disabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/mariadb.service.d
           └─dietpi-services_edit.conf
   Active: failed (Result: exit-code) since Fri 2021-03-12 21:47:26 CET; 12min ago
     Docs: man:mysqld(8)
           https://mariadb.com/kb/en/library/systemd/
  Process: 5860 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
  Process: 5861 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
  Process: 5863 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`cd /usr/bin/..; /usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)
  Process: 5921 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
 Main PID: 5921 (code=exited, status=1/FAILURE)
   Status: "MariaDB server is down"

Mar 12 21:42:52 DietPi systemd[1]: Starting MariaDB 10.3.27 database server...
Mar 12 21:42:55 DietPi mysqld[5921]: 2021-03-12 21:42:55 0 [Note] /usr/sbin/mysqld (mysqld 10.3.27-MariaDB-0+deb10u1) starting as process 5921 ...
Mar 12 21:42:55 DietPi mysqld[5921]: 2021-03-12 21:42:55 0 [Warning] Could not increase number of max_open_files to more than 16384 (request: 32186)
Mar 12 21:45:56 DietPi mysqld[5921]: 2021-03-12 21:45:56 0 [Warning] Can't create test file /var/lib/mysql/DietPi.lower-test
Mar 12 21:47:26 DietPi mysqld[5921]: [87B blob data]
Mar 12 21:47:26 DietPi mysqld[5921]: 2021-03-12 21:47:26 0 [ERROR] Aborting
Mar 12 21:47:26 DietPi systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
Mar 12 21:47:26 DietPi systemd[1]: mariadb.service: Failed with result 'exit-code'.
Mar 12 21:47:26 DietPi systemd[1]: Failed to start MariaDB 10.3.27 database server.

and

cat /var/log/mysql/error.log

returns the following:

2021-03-12 20:22:19 0 [Note] InnoDB: Using Linux native AIO
2021-03-12 20:22:19 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2021-03-12 20:22:19 0 [Note] InnoDB: Uses event mutexes
2021-03-12 20:22:19 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2021-03-12 20:22:19 0 [Note] InnoDB: Number of pools: 1
2021-03-12 20:22:19 0 [Note] InnoDB: Using generic crc32 instructions
2021-03-12 20:22:19 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2021-03-12 20:22:19 0 [Note] InnoDB: Completed initialization of buffer pool
2021-03-12 20:22:19 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2021-03-12 20:22:19 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1757567379
2021-03-12 20:24:21 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2021-03-12 20:24:52 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2021-03-12 20:24:52 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2021-03-12 20:24:52 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2021-03-12 20:24:52 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2021-03-12 20:24:52 0 [Note] InnoDB: 10.3.27 started; log sequence number 1757567388; transaction id 9877873
2021-03-12 20:24:52 0 [Note] InnoDB: Loading buffer pool(s) from /mnt/storage/dietpi_userdata/mysql/ib_buffer_pool
2021-03-12 20:24:52 0 [Note] Plugin 'FEEDBACK' is disabled.
2021-03-12 20:24:52 0 [Note] Recovering after a crash using tc.log
2021-03-12 20:24:52 0 [Note] Starting crash recovery...
2021-03-12 20:24:52 0 [Note] Crash recovery finished.
2021-03-12 20:24:52 0 [Note] Server socket created on IP: '127.0.0.1'.
2021-03-12 20:26:36 0 [Note] Reading of all Master_info entries succeeded
2021-03-12 20:26:36 0 [Note] Added new Master_info '' to hash table
2021-03-12 20:26:36 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.3.27-MariaDB-0+deb10u1'  socket: '/run/mysqld/mysqld.sock'  port: 3306  Raspbian 10
2021-03-12 20:29:16 10 [ERROR] mysqld: Incorrect information in file: './nextcloud/oc_calendar_rooms_md.frm'
2021-03-12 20:29:16 0 [Warning] InnoDB: Retry attempts for reading partial data failed.
2021-03-12 20:29:16 0 [ERROR] InnoDB: Tried to read 8192 bytes at offset 4251648, but was only able to read 0
2021-03-12 20:29:16 11 [Warning] InnoDB: Retry attempts for reading partial data failed.
2021-03-12 20:29:16 0 [ERROR] InnoDB: Operating system error number 5 in a file operation.
2021-03-12 20:29:16 11 [ERROR] InnoDB: Tried to read 8192 bytes at offset 0, but was only able to read 0
2021-03-12 20:29:16 0 [ERROR] InnoDB: Error number 5 means 'Input/output error'
2021-03-12 20:29:16 11 [ERROR] InnoDB: Operating system error number 5 in a file operation.
2021-03-12 20:29:16 0 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
2021-03-12 20:29:16 11 [ERROR] InnoDB: Error number 5 means 'Input/output error'
2021-03-12 20:29:16 11 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
2021-03-12 20:29:16 11 [ERROR] InnoDB: File (unknown): 'read' returned OS error 205. Cannot continue operation
2021-03-12 20:29:16 0 [ERROR] InnoDB: File (unknown): 'read' returned OS error 205. Cannot continue operation

I already tried setting the permissions via:

chown -R mysql:mysql /var/lib/mysql

and also to increase the max_open_files number without success.
I am also clueless on how to fix the incorrect information in the ‘oc_calendar_rooms_md.frm’-file.

Any tips or guidance would be appreciated!
Thanks!

Joulinar · 12 March 2021 22:19

Hi,

looks like some data corruption in Nextcloud calendar table. Not sure if there is a way to fix this as the database is not able to read that file.

Did you created a backup before running the update?

i_max · 12 March 2021 22:38

I did not… unfortunately. Maybe this will be enough for me to make a habit of it.

I do have the data in a different location, just not in associated with a database.

Is there a way to reinstall the mysql environment and then for me to reupload the data?

Joulinar · 12 March 2021 22:58

MichaIng
do you know if there is a way to export the database without the service being able to start?

i_max
what device you are using? Did you stored dietpi userdata on an external disk?

i_max · 13 March 2021 06:31

Yes, I did move the user data to a SSD. However when I checked my mounts I got this:

root@DietPi:~# ls -Al /mnt/
ls: cannot access '/mnt/storage': No such device
total 16
drwxr-xr-x 3 root root 4096 Feb 11  2020 dietpi-backup
lrwxrwxrwx 1 root root   28 Nov 28  2019 dietpi_userdata -> /mnt/storage/dietpi_userdata
drwxr-xr-x 2 root root 4096 Jul 14  2019 ftp_client
drwxr-xr-x 2 root root 4096 Jul 14  2019 nfs_client
drwxr-xr-x 2 root root 4096 Jul 14  2019 samba
d????????? ? ?    ?       ?            ? storage

my fstab looks like this:

# You can use "dietpi-drive_manager" to setup mounts.
# NB: It overwrites and re-creates physical drive mount entries on use.
#----------------------------------------------------------------
# NETWORK
#----------------------------------------------------------------


#----------------------------------------------------------------
# TMPFS
#----------------------------------------------------------------
tmpfs /tmp tmpfs defaults,size=1023M,noatime,nodev,nosuid,mode=1777 0 0
tmpfs /var/log tmpfs defaults,size=50m,noatime,nodev,nosuid,mode=1777 0 0

#----------------------------------------------------------------
# MISC: ecryptfs, vboxsf (VirtualBox shared folder), gluster, bind mounts
#----------------------------------------------------------------


#----------------------------------------------------------------
# SWAPFILE
#----------------------------------------------------------------
/var/swap none swap sw 0 0

#----------------------------------------------------------------
# PHYSICAL DRIVES
#----------------------------------------------------------------

Which leads me to a probably rather stupid question: can I just remount the drive via dietpi_drive_manager?
BTW the drive_manager takes an eternity to come up (couple of minutes). Network connection is fine. I am connected via PuTTY.

Joulinar · 13 March 2021 07:01

Looks like you SSD is not accessible at the moment. Can you try to unmount umount /mnt/storage

i_max · 13 March 2021 07:49

In the meantime I got my storage device mounted again, however it appears to be empty.
Not too surprising then that mariadb won’t start…

Joulinar · 13 March 2021 07:53

Does it fixed your issue?

i_max · 13 March 2021 08:19

I tried unmounting /mnt/storage but got an error saying it wasn’t mounted. So I mounted the drive.
Now mariadb is running again. I still can’t access the files in the nextcloud however. So it appears something is broken…
Thank you for your help.
Maybe I do have to reinstall the database?!

Joulinar · 13 March 2021 08:47

Before reinstall stuff, we should try to find out what the issue is.

MichaIng · 13 March 2021 14:41

AFAIK there is not way to dump the database to an .sql file without the daemon running. But the raw /mnt/dietpi_userdata/mysql files of course can be copied which will work fine with all MariaDB versions >= the one that created those tables.

If the drive is now mounted again, does ls -Al /mnt/dietpi_userdata/mysql/nextcloud show the database tables? And when MariaDB starts up fine, does it show any errors?

systemctl status mariadb
journalctl -u mariadb