Corrupt Nextcloud mysql database

Timbo · February 19, 2020, 6:04pm

My YunoHost server

Hardware: VPS running in the cloud, 512MB RAM
YunoHost version: 3.6.5.3
I have access to my server : Through SSH | through the webadmin
Are you in a special context or did you perform some particular tweaking on your YunoHost instance ? : Yes
If yes, please explain:

Description of my issue

The Datacenter that hosts Yuno underwent some maintenance last night and this morning, it was discovered that Nextcloud wasn’t starting. Checking on the server, the problem is corruption in mysql database. Starting innodb recovery, I get some more output:

root@website:/home/admin# journalctl -xe                                                                                                                                                                                              
-- The job identifier is 17612.                                                                                                                                                                                                    
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Warning] option 'table_open_cache': unsigned value 4 adjusted to 10
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] /usr/sbin/mysqld (mysqld 10.1.41-MariaDB-0+deb9u1) starting as process 31176 ...
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [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 p
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: Using mutexes to ref count buffer pool pages
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: The InnoDB memory heap is disabled
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: Compressed tables use zlib 1.2.8
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: Using Linux native AIO
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: Using SSE crc32 instructions
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: Initializing buffer pool, size = 128.0M
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: Completed initialization of buffer pool
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: Highest supported file format is Barracuda.
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [ERROR] InnoDB: Database page corruption on disk or a failed file read of tablespace ./ibdata1 page  [page id: space=0, page number=767]. You may have t
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19 09:22:41 7f99951b9800 InnoDB: Page dump in ascii and hex (16384 bytes):
Feb 19 09:22:41 website.ca mysqld[31176]:  len 16384; hex fc577485000002ff000000000000000000000000b7be5ea5000200000000000000000000000000022a0c2a31ffffffff0000ffffffff00000002295200000000000001ef177200000001000002ff002c000002ff002c
Feb 19 09:22:41 website.ca mysqld[31176]:               98 :   q;
Feb 19 09:22:41 website.ca mysqld[31176]: InnoDB: End of page dump
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19 09:22:41 7f99951b9800 InnoDB: uncompressed page, stored checksum in field1 4233589893, calculated checksums for field1: crc32 217247264, innodb 1593023686, none 3735928559, stor
Feb 19 09:22:41 website.ca mysqld[31176]: InnoDB: page type 2 meaning UNDO LOG
Feb 19 09:22:41 website.ca mysqld[31176]: InnoDB: Page may be an update undo log page
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: It is also possible that your operating system has corrupted its own file cache and rebooting your computer removes the error. If the cor
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [ERROR] InnoDB: Database page corruption on disk or a failed file read of tablespace ./ibdata1 page  [page id: space=0, page number=267]. You may have t
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19 09:22:41 7f99951b9800 InnoDB: Page dump in ascii and hex (16384 bytes):
Feb 19 09:22:41 website.ca mysqld[31176]:  len 16384; hex b346fea50000010b000000000000000000000000b7bd3da60006000000000000000000000000fffffffe0000000000000000ffffffff0000ffffffff000000000000000000f311720000018b0000016affffffffffff
Feb 19 09:22:41 website.ca mysqld[31176]:                R >  (y;
Feb 19 09:22:41 website.ca mysqld[31176]: InnoDB: End of page dump
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19 09:22:41 7f99951b9800 InnoDB: uncompressed page, stored checksum in field1 3007774373, calculated checksums for field1: crc32 956443286, innodb 3007774373, none 3735928559, stor
Feb 19 09:22:41 website.ca mysqld[31176]: InnoDB: page type 6 meaning SYS
Feb 19 09:22:41 website.ca mysqld[31176]: InnoDB: Page may be a system page
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: It is also possible that your operating system has corrupted its own file cache and rebooting your computer removes the error. If the cor
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: 128 rollback segment(s) are active.
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.44-86.0 started; log sequence number 3082708706
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] InnoDB: !!! innodb_force_recovery is set to 3 !!!
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] Plugin 'FEEDBACK' is disabled.
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297019324160 [Note] InnoDB: Dumping buffer pool(s) not yet started
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] Server socket created on IP: '::'.
Feb 19 09:22:41 website.ca mysqld[31176]: 2020-02-19  9:22:41 140297608337408 [Note] /usr/sbin/mysqld: ready for connections.
Feb 19 09:22:41 website.ca mysqld[31176]: Version: '10.1.41-MariaDB-0+deb9u1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Debian 9.9
Feb 19 09:22:41 website.ca /etc/mysql/debian-start[31203]: Upgrading MySQL tables if necessary.
Feb 19 09:22:41 website.ca /etc/mysql/debian-start[31208]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored
Feb 19 09:22:41 website.ca /etc/mysql/debian-start[31208]: Looking for 'mysql' as: /usr/bin/mysql
Feb 19 09:22:41 website.ca /etc/mysql/debian-start[31208]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Feb 19 09:22:41 website.ca /etc/mysql/debian-start[31208]: This installation of MySQL is already upgraded to 10.1.41-MariaDB, use --force if you still need to run mysql_upgrade
Feb 19 09:22:41 website.ca /etc/mysql/debian-start[31216]: Checking for insecure root accounts.
Feb 19 09:22:41 website.ca systemd[1]: Started MariaDB 10.1.41 database server.
-- Subject: A start job for unit mariadb.service has finished successfully
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A start job for unit mariadb.service has finished successfully.
-- 
-- The job identifier is 17612.
Feb 19 09:22:41 website.ca /etc/mysql/debian-start[31221]: Triggering myisam-recover for all MyISAM tables and aria-recover for all Aria tables
Feb 19 09:22:43 website.ca mysqld[31176]: InnoDB: innodb_force_recovery is on: we do not allow
Feb 19 09:22:43 website.ca mysqld[31176]: InnoDB: database modifications by the user. Shut down
Feb 19 09:22:43 website.ca mysqld[31176]: InnoDB: mysqld and edit my.cnf so thatInnoDB: innodb_force_... is removed.
Feb 19 09:22:48 website.ca mysqld[31176]: InnoDB: innodb_force_recovery is on: we do not allow
Feb 19 09:22:48 website.ca mysqld[31176]: InnoDB: database modifications by the user. Shut down
Feb 19 09:22:48 website.ca mysqld[31176]: InnoDB: mysqld and edit my.cnf so thatInnoDB: innodb_force_... is removed.
Feb 19 09:22:53 website.ca mysqld[31176]: InnoDB: innodb_force_recovery is on: we do not allow
Feb 19 09:22:53 website.ca mysqld[31176]: InnoDB: database modifications by the user. Shut down
Feb 19 09:22:53 website.ca mysqld[31176]: InnoDB: mysqld and edit my.cnf so thatInnoDB: innodb_force_... is removed.
Feb 19 09:22:56 website.ca mysqld[31176]: InnoDB: innodb_force_recovery is on: we do not allow
Feb 19 09:22:56 website.ca mysqld[31176]: InnoDB: database modifications by the user. Shut down
Feb 19 09:22:56 website.ca mysqld[31176]: InnoDB: mysqld and edit my.cnf so thatInnoDB: innodb_force_... is removed.

Unfortunately, it doesn’t look like i actually know the database name and the login info. I have recorded the root password, admin password, and all the users, but I don’t know the mysql info. sigh PEBKEC…

I also have borg backups that I take daily. Unfortunately, it appears am woefully under prepared here as well, as I’m struggling to see if the borg backup was taking a database backup and if I have any options to restore that.

My borg repo list shows a few days of backups:

auto_conf_17_02_20_00:00             Mon, 2020-02-17 00:00:28 [35bc98ec7f247e35c709afec759ced6b305b8773986668ca2d19c5232b176a0f]
auto_data_17_02_20_00:00             Mon, 2020-02-17 00:00:45 [54d478c2d1901bc9f5485f4fae3c62f261c41f98f30e14738c28337eaa167506]
auto_borg_17_02_20_00:00             Mon, 2020-02-17 00:00:59 [ac3f5ae62dd3451391f55af6fbaff08d0f81214271ed7a027bf5839fe5867318]
auto_rainloop_17_02_20_00:03         Mon, 2020-02-17 00:03:16 [61a3e8f6a4daa9400df3123e5aef91922e9da585d3fbcad5230e143a1345c54e]
auto_nextcloud_data_17_02_20_00:03   Mon, 2020-02-17 00:04:02 [86fe29de49a2695b426cddac59e0e4a142ca2ad1fe7fd84de75d186228574bbb]
auto_conf_18_02_20_00:00             Tue, 2020-02-18 00:00:22 [461d479b8e461e95c17a3e26686f9804d648d3ce7628e9782e63fa41a09a7e17]
auto_data_18_02_20_00:00             Tue, 2020-02-18 00:00:39 [e8e8987b762cab02436dfd4e20ef42288680b3eab6cf23c7f1589fd4b397c7d0]
auto_borg_18_02_20_00:00             Tue, 2020-02-18 00:00:52 [63305f59d1f1da06e49fd4d845b93108cdd55f617aaad27101b8cbbc31c8ac17]
auto_rainloop_18_02_20_00:02         Tue, 2020-02-18 00:02:14 [5831e566bd64f41293c6ac3383a66461babb3560b151701e3e715d317e0ff328]
auto_nextcloud_data_18_02_20_00:02   Tue, 2020-02-18 00:02:53 [d9bc54c2533d17643364e8aee3d0ffe7086560b1f4b35b1cf8886e1878868ff8]
auto_nextcloud_19_02_20_00:01        Wed, 2020-02-19 00:01:31 [fee604e2763091669f2cf209d53e848adfef749a260251a90fc1705b3c45ca6c]
auto_rainloop_19_02_20_00:02         Wed, 2020-02-19 00:02:21 [db28ccd95614d4c7bd8f8b48f2cfdee8c59fe3e8b5fbfe0d65ef3c74824216ef]
auto_nextcloud_data_19_02_20_00:02   Wed, 2020-02-19 00:03:03 [5f75b5609d21c3bf414d171ba146b1e9a18f03f5ef4d94465255bb42a7cd5d98]
auto_conf_19_02_20_02:03             Wed, 2020-02-19 02:04:00 [1b3c858c2e38ca686dbd9fe5ba6ac7f96fa3655eb331a96e0633e2f01436cf13]
auto_data_19_02_20_02:04             Wed, 2020-02-19 02:04:58 [60d8671872e55b82c8014da5393f726ecacb811a137ce1709a115cb811a72852]
auto_borg_19_02_20_02:05             Wed, 2020-02-19 02:05:16 [fb04530ba8928f6baa402b359966828ec6b9e912d636c084be88712fa80ef411]
auto_conf_19_02_20_08:50             Wed, 2020-02-19 08:50:42 [cfcc66f59a17e7c9fe9947fafd02b956382e5e0db0a6704ffbe82d797b29a489]
auto_data_19_02_20_08:50             Wed, 2020-02-19 08:50:55 [eb83434a5866fe51099be4ba95c71e2fcc53b138e05bfe79558e87d9660b6934]
auto_borg_19_02_20_08:51             Wed, 2020-02-19 08:51:07 [9a5e7998264c6943cff6b457c991b15f3e1546e34df9e895b25d95227563bf5a]

Now I’m unsure of how to proceed to restore Nextcloud database and get it operational again. Can good Samaritan suggest how to move forward? I’m really feeling the stress of one who thought they had backups and then realizing it wasn’t properly thought out ahead of time. I would be really greatful to any suggestions.

Thanks!

ljf · February 19, 2020, 6:21pm

If you want to restore specifically the db:

You can use borg list to list a specific archives and find the path of sql file:

borg list REPO::auto_nextcloud_19_02_20_00:01 | grep db.sql

And extract it:

borg extract REPO::auto_nextcloud_19_02_20_00:01 path/to/your/db.sql

Next you can run:

source /usr/share/yunohost/helpers
ynh_mysql_remove_db --db_user=nextcloud --db_name=nextcloud
ynh_mysql_setup_db --db_user=nextcloud --db_name=nextcloud --db_pwd=$(grep -Po "mysqlpwd: \K(.*)$" /etc/yunohost/apps/nextcloud/settings.yml)
ynh_mysql_connect_as --user=nextcloud --password=$(grep -Po "mysqlpwd: \K(.*)$" /etc/yunohost/apps/nextcloud/settings.yml) --database=nextcloud < path/to/your/db.sql

Note: In some case it could be more complicated if mysql is completely broken and don’t start.
Note2: an other solution is to restore nextcloud entirely

Timbo · February 19, 2020, 6:28pm

Thank you so much. Unfortunately, password issue? Should I be doing this as root instead of admin user?

admin@website:~$ source /usr/share/yunohost/helpers
admin@website:~$ ynh_mysql_remove_db --db_user=nextcloud --db_name=nextcloud
++ sudo cat /etc/yunohost/mysql
+ local mysql_root_password=UrN4Vx7HZp
+ grep -q '^| nextcloud'
+ mysqlshow -u root -pUrN4Vx7HZp
mysqlshow: Access denied for user 'root'@'localhost'
+ ynh_print_warn '--message=Database nextcloud not found'
+ local legacy_args=m
+ args_array=([m]=message=)
+ declare -Ar args_array
+ local message
+ ynh_handle_getopts_args '--message=Database nextcloud not found'
+ set +x
+ ynh_print_log '\e[93m\e[1m[WARN]\e[0m Database nextcloud not found'
+ echo -e '\e[93m\e[1m[WARN]\e[0m Database nextcloud not found'
[WARN] Database nextcloud not found
++ ynh_mysql_user_exists --user=nextcloud
++ local legacy_args=u
++ args_array=([u]=user=)
++ declare -Ar args_array
++ local user
++ ynh_handle_getopts_args --user=nextcloud
++ set +x
+++ ynh_mysql_execute_as_root '--sql=SELECT User from mysql.user WHERE User = '\''nextcloud'\'';'
+++ local legacy_args=sd
+++ args_array=([s]=sql= [d]=database=)
+++ declare -Ar args_array
+++ local sql
+++ local database
+++ ynh_handle_getopts_args '--sql=SELECT User from mysql.user WHERE User = '\''nextcloud'\'';'
+++ set +x
+++ database=
++++ sudo cat /etc/yunohost/mysql
+++ ynh_mysql_connect_as --user=root --password=UrN4Vx7HZp --database=
+++ local legacy_args=upd
+++ args_array=([u]=user= [p]=password= [d]=database=)
+++ declare -Ar args_array
+++ local user
+++ local password
+++ local database
+++ ynh_handle_getopts_args --user=root --password=UrN4Vx7HZp --database=
+++ set +x
+++ database=
+++ mysql -u root --password=UrN4Vx7HZp -B ''
ERROR 1698 (28000): Access denied for user 'root'@'localhost'
++ [[ -z '' ]]
++ return 1

Thanks

ljf · February 19, 2020, 6:29pm

Yes you need to run this as root, mysql password of the old table is only available to root and nextcloud user.

Timbo · February 19, 2020, 6:33pm

Getting closer, but got traceback on the ynh_mysql_setup_db command:

root@website:/home/admin/apps/nextcloud/backup# ynh_mysql_setup_db --db_user=nextcloud --db_name=nextcloud --db_pwd=$(grep -Po "mysqlpwd: \K(.*)$" /etc/yunohost/apps/nextcloud/settings.yml)
++ grep -Po 'mysqlpwd: \K(.*)$' /etc/yunohost/apps/nextcloud/settings.yml
+ ynh_mysql_setup_db --db_user=nextcloud --db_name=nextcloud --db_pwd=t8QfFvrsS05z8xSiSTjXsqi8
+ local legacy_args=unp
+ args_array=([u]=db_user= [n]=db_name= [p]=db_pwd=)
+ declare -Ar args_array
+ local db_user
+ local db_name
+ db_pwd=
+ ynh_handle_getopts_args --db_user=nextcloud --db_name=nextcloud --db_pwd=t8QfFvrsS05z8xSiSTjXsqi8
+ set +x
++ ynh_string_random
++ local legacy_args=l
++ args_array=([l]=length=)
++ declare -Ar args_array
++ local length
++ ynh_handle_getopts_args
++ set +x
++ length=24
++ dd if=/dev/urandom bs=1 count=1000
++ tr -c -d A-Za-z0-9
++ sed -n 's/\(.\{24\}\).*/\1/p'
+ local new_db_pwd=BXV75umlLrXy5GCmrg6JZwYl
+ db_pwd=t8QfFvrsS05z8xSiSTjXsqi8
+ ynh_mysql_create_db nextcloud nextcloud t8QfFvrsS05z8xSiSTjXsqi8
+ local db=nextcloud
+ local 'sql=CREATE DATABASE nextcloud;'
+ [[ 3 -gt 1 ]]
+ sql+=' GRANT ALL PRIVILEGES ON nextcloud.* TO '\''nextcloud'\''@'\''localhost'\'''
+ [[ -n t8QfFvrsS05z8xSiSTjXsqi8 ]]
+ sql+=' IDENTIFIED BY '\''t8QfFvrsS05z8xSiSTjXsqi8'\'''
+ sql+=' WITH GRANT OPTION;'
+ ynh_mysql_execute_as_root '--sql=CREATE DATABASE nextcloud; GRANT ALL PRIVILEGES ON nextcloud.* TO '\''nextcloud'\''@'\''localhost'\'' IDENTIFIED BY '\''t8QfFvrsS05z8xSiSTjXsqi8'\'' WITH GRANT OPTION;'
+ local legacy_args=sd
+ args_array=([s]=sql= [d]=database=)
+ declare -Ar args_array
+ local sql
+ local database
+ ynh_handle_getopts_args '--sql=CREATE DATABASE nextcloud; GRANT ALL PRIVILEGES ON nextcloud.* TO '\''nextcloud'\''@'\''localhost'\'' IDENTIFIED BY '\''t8QfFvrsS05z8xSiSTjXsqi8'\'' WITH GRANT OPTION;'
+ set +x
+ database=
++ sudo cat /etc/yunohost/mysql
+ ynh_mysql_connect_as --user=root --password=UrN4Vx7HZp --database=
+ local legacy_args=upd
+ args_array=([u]=user= [p]=password= [d]=database=)
+ declare -Ar args_array
+ local user
+ local password
+ local database
+ ynh_handle_getopts_args --user=root --password=UrN4Vx7HZp --database=
+ set +x
+ database=
+ mysql -u root --password=UrN4Vx7HZp -B ''
+ ynh_app_setting_set --app= --key=mysqlpwd --value=t8QfFvrsS05z8xSiSTjXsqi8
+ local legacy_args=akv
+ args_array=([a]=app= [k]=key= [v]=value=)
+ declare -Ar args_array
+ local app
+ local key
+ local value
+ ynh_handle_getopts_args --app= --key=mysqlpwd --value=t8QfFvrsS05z8xSiSTjXsqi8
+ set +x
+ ynh_app_setting set '' mysqlpwd t8QfFvrsS05z8xSiSTjXsqi8
+ ACTION=set
+ APP=
+ KEY=mysqlpwd
+ VALUE=t8QfFvrsS05z8xSiSTjXsqi8
+ python -
Traceback (most recent call last):
  File "<stdin>", line 5, in <module>
AssertionError: Setting file /etc/yunohost/apps//settings.yml does not exists ?

ljf · February 19, 2020, 6:35pm

Indeed but you can ignore it, ynh_mysql_setup_db normally run in an app script context, but this psecific error at the end of ynh_mysql_setup_db is not important in this situation.

Timbo · February 19, 2020, 6:37pm

On last command:

# ynh_mysql_connect_as --user=nextcloud --password=$(grep -Po "mysqlpwd: \K(.*)$" /etc/yunohost/apps/nextcloud/settings.yml) --database=nextcloud < /home/admin/apps/nextcloud/backup/db.sql
++ grep -Po 'mysqlpwd: \K(.*)$' /etc/yunohost/apps/nextcloud/settings.yml
+ ynh_mysql_connect_as --user=nextcloud --password=t8QfFvrsS05z8xSiSTjXsqi8 --database=nextcloud
+ local legacy_args=upd
+ args_array=([u]=user= [p]=password= [d]=database=)
+ declare -Ar args_array
+ local user
+ local password
+ local database
+ ynh_handle_getopts_args --user=nextcloud --password=t8QfFvrsS05z8xSiSTjXsqi8 --database=nextcloud
+ set +x
+ database=nextcloud
+ mysql -u nextcloud --password=t8QfFvrsS05z8xSiSTjXsqi8 -B nextcloud
ERROR 1036 (HY000) at line 38: Table 'oc_accounts' is read only

Mysql is currently running with innodb_force_recovery = 3. Any idea what I should do to run the last command successfully? I am assuming the read-only part is from being in recovery. Maybe I shouldn’t be?

Edit: Set the recovery back to 0, and mysql started because the corrupt db was thrown out. Then the last command worked successfully and web login to Nextcloud working.

Thank you, thank you, thank you. I’d like to buy you a beer or two.

ljf · February 19, 2020, 6:41pm

Yes i think you should run without innodb_force_recovery = 3 if possible.

Timbo · February 20, 2020, 12:03pm

@ljf

sigh The saga continues.

After following your advice this morning, I was able to successfully restore the database and see Nextcloud running in the browser and with the app.

2 hours later, I got a notification the server was offline. 4 hours later the server came back up, and again Maria db was failing to start. So I attempted to restore the database again, but this time I am getting stuck on the last step.

In order for the 2nd and 3rd command to work, mysql needs to be running. I can only get mysql running if recovery = 3. Earlier in the day, I was able to run commands 2 and 3 when recovery = 3. But when trying the 4th command, I got “ERROR 1036 (HY000) at line 38: Table ‘oc_accounts’ is read only”. Luckily, I was able to change recovery to 0, restart mariadb and then successfully run it and get things working.

Unfortunately, I can’t get Mariadb to start with any recovery option but 3.

With recovery set to 0, Mariadb just fails with:

# journalctl -xe
Feb 20 03:51:13 website.ca mysqld[14872]: InnoDB: If you get repeated assertion failures or crashes, even                                                                                                                             
Feb 20 03:51:13 website.ca mysqld[14872]: InnoDB: immediately after the mysqld startup, there may be
Feb 20 03:51:13 website.ca mysqld[14872]: InnoDB: corruption in the InnoDB tablespace. Please refer to
Feb 20 03:51:13 website.ca mysqld[14872]: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Feb 20 03:51:13 website.ca mysqld[14872]: InnoDB: about forcing recovery.
Feb 20 03:51:13 website.ca mysqld[14872]: 200220  3:51:13 [ERROR] mysqld got signal 6 ;
Feb 20 03:51:13 website.ca mysqld[14872]: This could be because you hit a bug. It is also possible that this binary
Feb 20 03:51:13 website.ca mysqld[14872]: or one of the libraries it was linked against is corrupt, improperly built,
Feb 20 03:51:13 website.ca mysqld[14872]: or misconfigured. This error can also be caused by malfunctioning hardware.
Feb 20 03:51:13 website.ca mysqld[14872]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
Feb 20 03:51:13 website.ca mysqld[14872]: We will try our best to scrape up some info that will hopefully help
Feb 20 03:51:13 website.ca mysqld[14872]: diagnose the problem, but since we have already crashed,
Feb 20 03:51:13 website.ca mysqld[14872]: something is definitely wrong and this may fail.
Feb 20 03:51:13 website.ca mysqld[14872]: Server version: 10.1.44-MariaDB-0+deb9u1
Feb 20 03:51:13 website.ca mysqld[14872]: key_buffer_size=16384
Feb 20 03:51:13 website.ca mysqld[14872]: read_buffer_size=262144
Feb 20 03:51:13 website.ca mysqld[14872]: max_used_connections=0
Feb 20 03:51:13 website.ca mysqld[14872]: max_threads=153
Feb 20 03:51:13 website.ca mysqld[14872]: thread_count=0
Feb 20 03:51:13 website.ca mysqld[14872]: It is possible that mysqld could use up to
Feb 20 03:51:13 website.ca mysqld[14872]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 52132 K  bytes of memory
Feb 20 03:51:13 website.ca mysqld[14872]: Hope that's ok; if not, decrease some variables in the equation.
Feb 20 03:51:13 website.ca mysqld[14872]: Thread pointer: 0x0
Feb 20 03:51:13 website.ca mysqld[14872]: Attempting backtrace. You can use the following information to find out
Feb 20 03:51:13 website.ca mysqld[14872]: where mysqld died. If you see no messages after this, something went
Feb 20 03:51:13 website.ca mysqld[14872]: terribly wrong...
Feb 20 03:51:13 website.ca mysqld[14872]: stack_bottom = 0x0 thread_stack 0x20000
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55601a21121e]
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(handle_fatal_signal+0x3bd)[0x556019d5d40d]
Feb 20 03:51:13 website.ca mysqld[14872]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x110e0)[0x7fa74f3320e0]
Feb 20 03:51:13 website.ca mysqld[14872]: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcf)[0x7fa74dbfdfff]
Feb 20 03:51:13 website.ca mysqld[14872]: /lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7fa74dbff42a]
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(+0x3697b5)[0x556019b067b5]
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(+0xa01ad1)[0x55601a19ead1]
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(+0x92e53b)[0x55601a0cb53b]
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(+0x949743)[0x55601a0e6743]
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(+0x94010e)[0x55601a0dd10e]
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(+0x9413a8)[0x55601a0de3a8]
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(+0x938b3b)[0x55601a0d5b3b]
Feb 20 03:51:13 website.ca mysqld[14872]: /usr/sbin/mysqld(+0x938f31)[0x55601a0d5f31]
Feb 20 03:51:13 website.ca mysqld[14872]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x74a4)[0x7fa74f3284a4]
Feb 20 03:51:13 website.ca mysqld[14872]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fa74dcb3d0f]
Feb 20 03:51:13 website.ca mysqld[14872]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Feb 20 03:51:13 website.ca mysqld[14872]: information that should help you find out what is causing the crash.
Feb 20 03:51:13 website.ca systemd[1]: mariadb.service: Main process exited, code=killed, status=6/ABRT
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- An ExecStart= process belonging to unit mariadb.service has exited.
-- 
-- The process' exit code is 'killed' and its exit status is 6.
Feb 20 03:51:13 website.ca systemd[1]: mariadb.service: Failed with result 'signal'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- The unit mariadb.service has entered the 'failed' state with result 'signal'.
Feb 20 03:51:13 website.ca systemd[1]: Failed to start MariaDB 10.1.44 database server.
-- Subject: A start job for unit mariadb.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A start job for unit mariadb.service has finished with a failure.
-- 
-- The job identifier is 375775 and the job result is failed.

At this point, I really don’t know how to proceed. Is mariadb broken beyond repair?

Thanks again

Benance · February 20, 2020, 2:29pm

Hello
You have to

set innodb_force_recovery = 3
launch mariadb
restore your database
stop mariadb
remove the line innodb_force_recovery = 3
start mariadb again

Timbo · February 20, 2020, 7:21pm

@Benance ,

Unfortunately, with step 3 of those steps, I get a mysql error "ERROR 1036 (HY000) at line 38: Table ‘oc_accounts’ is read only”. That’s the issue I need to get past. Previously, if I did your step 3 after step 5, it took. Just not now/anymore.

Thanks

Timbo · February 20, 2020, 8:53pm

If I can’t get past this database issue, I think I have two options:

Blow away mysql files, remove, reinstall, reimport from backup. Yuno, Nextcloud, Borg and Rainloop are the only apps.
Make a new VPS, restore from backups from borg.

Any documentation available on the steps for either? I for sure wouldn’t have figured out the commands supplied yesterday, so I’m hoping someone has gone through this before. The first one with just the databases would be least work, and a new server being the most. But I don’t know how to proceed with the "ERROR 1036 (HY000) at line 38: Table ‘oc_accounts’ is read only” blocking me from importing my backup.

Timbo · February 20, 2020, 9:09pm

Also, is there another mysql log to look at that might explain how mariadb is busted? In /var/log/mysql, error.log is empty.

Timbo · February 21, 2020, 8:46am

Alright, looks like I got Nextcloud running again! I forget the order of operations, but some of my notes:

This site was useful: https://forums.cpanel.net/resources/innodb-corruption-repair-guide.395/

mv /var/lib/mysql/ibdata* /tmp/
mv /var/lib/mysql/ib_log* /tmp/

This allowed mariadb to run without recovery enabled, IIRC.

I think it was increasing the recovery number, I could see more log output, such as:

Feb 21 00:24:03 website.ca /etc/mysql/debian-start[22256]: Phase 4/7: Running 'mysql_fix_privilege_tables'
Feb 21 00:24:03 website.ca /etc/mysql/debian-start[22256]: ERROR 1932 (42S02) at line 592: Table 'mysql.innodb_index_stats' doesn't exist in engine
Feb 21 00:24:03 website.ca /etc/mysql/debian-start[22256]: ERROR 1243 (HY000) at line 593: Unknown prepared statement handler (stmt) given to EXECUTE
Feb 21 00:24:03 website.ca /etc/mysql/debian-start[22256]: ERROR 1932 (42S02) at line 595: Table 'mysql.innodb_table_stats' doesn't exist in engine
Feb 21 00:24:03 website.ca /etc/mysql/debian-start[22256]: ERROR 1243 (HY000) at line 596: Unknown prepared statement handler (stmt) given to EXECUTE
Feb 21 00:24:03 website.ca /etc/mysql/debian-start[22256]: ERROR 1932 (42S02) at line 600: Table 'mysql.innodb_index_stats' doesn't exist in engine
Feb 21 00:24:03 website.ca /etc/mysql/debian-start[22256]: ERROR 1932 (42S02) at line 604: Table 'mysql.innodb_table_stats' doesn't exist in engine
Feb 21 00:24:03 website.ca /etc/mysql/debian-start[22256]: ERROR 1932 (42S02) at line 607: Table 'mysql.innodb_table_stats' doesn't exist in engine
Feb 21 00:24:03 website.ca /etc/mysql/debian-start[22256]: FATAL ERROR: Upgrade failed

This link was very useful for getting the queries to recreate the tables: https://stackoverflow.com/questions/37856155/mysql-upgrade-failed-innodb-tables-doesnt-exist

Needed to drop 3 tables and move their ibd files out of the mysql dir before adding the tables back with the queries at the url above.

After that, I could restart mariadb without any glaring errors in my face, so then I was able to do the 4 commands to drop and recreate the Nextcloud database and then import the backup. Within a minute of doing this, Nextcloud desktop client popped up to indicate it was connected and doing its thang again.

It looks like this might be an old mysql/mariadb bug that has long been fixed in 10.2+. But I guess that is a Debian 10 thing, not 9…

Thanks guys! Crossing fingers I don’t need to do this again in 2-4 hours…

system · March 7, 2020, 8:46am

This topic was automatically closed 15 days after the last reply. New replies are no longer allowed.