Unable to start Mysql - Force Recovery not working

Keywords: WordPress - Google Cloud Platform - Technical issue - Services (Apache, MariaDB, MySQL…)

bnsupport ID: 8e7e4c21-afaf-49c1-03cb-db5f06438702

bndiagnostic output:

? Apache: Found possible issues
? Mysql: Found possible issues
https://docs.bitnami.com/general/apps/wordpress/administration/use-pagespeed/#disable-pagespeed
https://docs.bitnami.com/general/apps/wordpress/troubleshooting/debug-errors-apache/
https://docs.bitnami.com/bch/apps/moodle/troubleshooting/deny-connections-bots-apache/
https://docs.bitnami.com/aws/apps/wordpress/troubleshooting/debug-errors-mysql/

bndiagnostic failure reason: The documentation did not make any significant change

Description:
I’ve been unable to start Mysql for a couple of days. The website stopped working suddenly with “Error establishing a database connection” in the WordPress site.
After looking at the forums I found out bin.logs had (presumably) caused the issue, so I disabled them and freed space. Now there should be space enough but it is still not starting.

Bitnami Diagnostic Tool shows:

Found recent error messages in the MySQL error log:
Most likely, you have hit a bug, but this error can also be caused by 
malfunctioning hardware.

InnoDB Force Recovery shows:

2021-07-27T16:05:48.021598Z 0 [Warning] [MY-010091] [Server] Can't create test file /opt/bitnami/mysql/data/mysqld_tmp_file_case_insensitive_test.lower-test
2021-07-27T16:05:48.021609Z 0 [Warning] [MY-010159] [Server] Setting lower_case_table_names=2 because file system for /opt/bitnami/mysql/data/ is case insensitive
2021-07-27T16:05:48.021928Z 0 [Warning] [MY-010122] [Server] One can only use the --user switch if running as root
2021-07-27T16:05:48.030071Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2021-07-27T16:05:48.030273Z 1 [ERROR] [MY-012271] [InnoDB] The innodb_system data file 'ibdata1' must be writable
2021-07-27T16:05:48.030373Z 1 [ERROR] [MY-012278] [InnoDB] The innodb_system data file 'ibdata1' must be writable
2021-07-27T16:05:48.030499Z 1 [ERROR] [MY-010334] [Server] Failed to initialize DD Storage Engine
2021-07-27T16:05:48.030745Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2021-07-27T16:05:48.030861Z 0 [ERROR] [MY-010119] [Server] Aborting
2021-07-27T16:05:48.031494Z 0 [System] [MY-010910] [Server] /opt/bitnami/mysql/bin/mysqld.bin: Shutdown complete (mysqld 8.0.23)  MySQL Community Server - GPL.

Permissions are standard 750 mysql:root.

Hi @judith.agundez,

Thanks for using Bitnami. We highly recommend you to create a server backup before doing any other change to your server to be able to get back to the previous state if anything goes wrong.

https://docs.bitnami.com/google/faq/administration/backup-restore-server/

The error message you shared, mentions the ibdata1 file, which has the current permissions in your system

-rwxr-xr-x  1 mysql root 12582912 Jul 22 15:22 ibdata1

As you see, it has the execution permission granted, which I don’t know if it is causing errors. Original file permissions are different

-rw-r-----  1 mysql root  12582912 Mar 26 08:16 ibdata1

Can you reset the permissions for the files in that folder? I think running the next commands is a good starting point

sudo chown -R mysql:root /opt/bitnami/mysql/data
sudo chown -R mysql:mysql /opt/bitnami/mysql/data/bitnami_wordpress
sudo find /opt/bitnami/mysql/data -maxdepth 1 -type f -exec chmod 640 "{}" ";"

After that, please try to start MySQL again and check the new errors in case it doesn’t start

1 Like

Hi @gongomgra,

Thanks for your help! Unfortunately, I’m still stuck with the following:

2021-07-28T10:03:27.443104Z 0 [System] [MY-010116] [Server] /opt/bitnami/mysql/bin/mysqld.bin (mysqld 8.0.23) starting as process 31047
2021-07-28T10:03:27.446708Z 0 [Warning] [MY-010091] [Server] Can't create test file /opt/bitnami/mysql/data/mysqld_tmp_file_case_insensitive_test.lower-test
2021-07-28T10:03:27.446719Z 0 [Warning] [MY-010159] [Server] Setting lower_case_table_names=2 because file system for /opt/bitnami/mysql/data/ is case insensitive
2021-07-28T10:03:27.447022Z 0 [Warning] [MY-010122] [Server] One can only use the --user switch if running as root
2021-07-28T10:03:27.447045Z 0 [ERROR] [MY-013276] [Server] Failed to set datadir to '/opt/bitnami/mysql/data/' (OS errno: 13 - Permission denied)
2021-07-28T10:03:27.447472Z 0 [ERROR] [MY-010119] [Server] Aborting
2021-07-28T10:03:27.447711Z 0 [System] [MY-010910] [Server] /opt/bitnami/mysql/bin/mysqld.bin: Shutdown complete (mysqld 8.0.23)  MySQL Community Server - GPL.

ibdata1 seems solved, but now it’s permission denied. Seems something wrong with Mysql user permissions?

BDT doesn’t show any extra problems
984f5b3c-ae04-81db-80d7-e4eacc13b266

Hi @judith.agundez,

Thanks for the info. I can’t find the error message you shared in the new bnsupport bundle. Also the /opt/bitnami/mysql/data permissions seems to be fine.

drwxr-x---  7 mysql root    4096 Jul 28 09:52 data

Can you check you are running the bnsupport tool in the server you are getting issues with? Can you also share the output of running the next commands with us?

sudo ls -lart /opt/bitnami
sudo ls -lart /opt/bitnami/mysql
sudo ls -lart /opt/bitnami/mysql/data
1 Like

Hi!
I just ran it again: a5bc5543-df06-55c4-f922-9595e069d0ed

As for the results of the commands:

 sudo ls -lart /opt/bitnami

total 3504
-rwx------  1 root    root    3390885 Aug 27  2019 manager-linux-x64.run
-rw-r--r--  1 root    root        754 Apr 15  2020 bnsupport-regex.ini
drwxr-xr-x 10 root    root       4096 Mar 26 08:12 common
drwxr-xr-x  2 root    root       4096 Mar 26 08:13 bncert
lrwxrwxrwx  1 root    root         46 Mar 26 08:13 bncert-tool -> /opt/bitnami/bncert/bncert-0.6.2-linux-x64.run
drwxr-xr-x  2 root    root       4096 Mar 26 08:13 bnhelper
lrwxrwxrwx  1 root    root         50 Mar 26 08:13 bnhelper-tool -> /opt/bitnami/bnhelper/bnhelper-0.1.0-linux-x64.
run
drwxr-xr-x  5 root    root       4096 Mar 26 08:13 sqlite
drwxr-xr-x  9 root    root       4096 Mar 26 08:13 varnish
-rwxr-xr-x  1 root    root      41732 Mar 26 08:13 ctlscript.sh
drwxr-xr-x  2 root    root       4096 Mar 26 08:13 img
-rwxr--r--  1 root    root        308 Mar 26 08:14 use_wordpress
drwxr-xr-x 12 root    root       4096 Mar 26 08:15 php
drwxr-xr-x 14 root    root       4096 Mar 26 08:15 apache2
-rw-r--r--  1 root    root      12668 Mar 26 08:16 README.txt
-rw-r--r--  1 root    root      33469 Mar 26 08:16 changelog.txt
drwxr-xr-x  3 root    root       4096 Mar 26 08:17 scripts
-rwxr-xr-x  1 root    root       1886 Mar 26 08:17 configure_app_domain
drwxr-xr-x  3 root    root       4096 Mar 26 08:18 licenses
drwxr-xr-x  4 root    root       4096 Mar 26 08:20 ..
drwxr-xr-x  5 root    root       4096 Mar 26 08:20 config
drwxr-xr-x  7 root    root       4096 Apr 27 11:09 var
drwxr-xr-x  4 bitnami root       4096 Apr 27 11:15 letsencrypt
drwxr-xr-x  6 root    root       4096 May 27 13:52 apps
-rwxrwx---  1 bitnami root       1927 May 27 13:53 properties.ini
lrwxrwxrwx  1 root    root         53 Jul 26 17:30 bnsupport-tool -> /opt/bitnami/bnsupport/bnsupport-0.9.12-linux-
x64.run
drwxr-xr-x  3 root    root       4096 Jul 26 17:30 bnsupport
drwxr-xr-x 11 mysql   root       4096 Jul 27 16:05 mysql
drwxr-xr-x  3 root    root       4096 Jul 28 10:00 bndiagnostic
lrwxrwxrwx  1 root    root         41 Jul 28 10:01 bndiagnostic-tool -> /opt/bitnami/bndiagnostic/bndiagnostic.sh
drwxr-xr-x 20 root    root       4096 Jul 28 10:01 .
drwxr-xr-x  2 bitnami bitnami    4096 Jul 29 10:09 stats
sudo ls -lart /opt/bitnami/mysql

total 8804
-rwxr-xr-x  1 mysql root     666 Dec 11  2020 README
-rwxr-xr-x  1 mysql root  382369 Dec 11  2020 LICENSE
-rwxr-xr-x  1 mysql root 8574902 Mar 26 07:45 bnconfig
drwxr-xr-x  2 mysql root    4096 Mar 26 08:13 support-files
drwxr-xr-x 28 mysql root    4096 Mar 26 08:13 share
drwxr-xr-x  2 mysql root    4096 Mar 26 08:13 scripts
drwxr-xr-x  3 mysql root    4096 Mar 26 08:13 include
drwxr-xr-x  2 mysql root    4096 Mar 26 08:13 bin
drwxr-xr-x  6 mysql root    4096 Mar 26 08:13 lib
drwxr-xr-x  2 mysql root    4096 May 28 21:31 bitnami
-rwxr-xr-x  1 mysql root     731 Jul 27 16:05 my.cnf
drwxr-xr-x 11 mysql root    4096 Jul 27 16:05 .
drwxr-x---  7 mysql root    4096 Jul 28 09:52 data
drwxr-xr-x  2 mysql root    4096 Jul 28 09:52 tmp
drwxr-xr-x 20 root  root    4096 Jul 28 10:01 ..
sudo ls -lart /opt/bitnami/mysql/data

total 190148
drwxr-x---  2 mysql root     4096 Mar 26 08:14  performance_schema
-rw-r-----  1 mysql root       56 Mar 26 08:14  auto.cnf
-rw-r-----  1 mysql root     1680 Mar 26 08:14  ca-key.pem
-rw-r-----  1 mysql root     1112 Mar 26 08:14  ca.pem
-rw-r-----  1 mysql root     1680 Mar 26 08:14  server-key.pem
-rw-r-----  1 mysql root     1112 Mar 26 08:14  server-cert.pem
-rw-r-----  1 mysql root     1680 Mar 26 08:14  client-key.pem
-rw-r-----  1 mysql root     1112 Mar 26 08:14  client-cert.pem
-rw-r-----  1 mysql root      452 Mar 26 08:14  public_key.pem
-rw-r-----  1 mysql root     1680 Mar 26 08:14  private_key.pem
drwxr-x---  2 mysql root     4096 Mar 26 08:14  mysql
drwxr-x---  2 mysql root     4096 Mar 26 08:14  sys
-rw-r-----  1 mysql root     3945 Apr 27 11:09  ib_buffer_pool
-rw-r-----  1 mysql root     1254 Apr 27 11:09  nasodren-web-de-vm.err
-rw-r-----  1 mysql root      623 Apr 27 11:09  mysqld.log-20210502.gz
-rw-r-----  1 mysql root       20 May  2 00:00  mysqld.log-20210509.gz
-rw-r-----  1 mysql root      512 May  9 23:08  mysqld.log-20210516.gz
-rw-r-----  1 mysql root       20 May 16 00:00  mysqld.log-20210523.gz
drwxr-x---  2 mysql root     4096 May 28 21:31 '#innodb_temp'
-rw-r-----  1 mysql root 12582912 May 28 21:31  ibtmp1
-rw-r-----  1 mysql root     2732 May 28 21:31  mysqld.log-20210530.gz
-rw-r-----  1 mysql root       20 May 30 00:00  mysqld.log-20210606.gz
-rw-r-----  1 mysql root       20 Jun  6 00:00  mysqld.log-20210613.gz
-rw-r-----  1 mysql root       20 Jun 13 00:00  mysqld.log-20210620.gz
-rw-r-----  1 mysql root       20 Jun 20 00:00  mysqld.log-20210627.gz
-rw-r-----  1 mysql root       20 Jun 27 00:00  mysqld.log-20210704.gz
-rw-r-----  1 mysql root       20 Jul  4 00:00  mysqld.log-20210711.gz
-rw-r-----  1 mysql root       20 Jul 11 00:00  mysqld.log-20210718.gz
-rw-r-----  1 mysql root  8585216 Jul 22 09:44 '#ib_16384_1.dblwr'
drwxr-x---  2 mysql root    12288 Jul 22 15:21  bitnami_wordpress
-rw-r-----  1 mysql root 50331648 Jul 22 15:22  ib_logfile1
-rw-r-----  1 mysql root 50331648 Jul 22 15:22  ib_logfile0
-rw-r-----  1 mysql root 16777216 Jul 22 15:22  undo_001
-rw-r-----  1 mysql root 16777216 Jul 22 15:22  undo_002
-rw-r-----  1 mysql root 26214400 Jul 22 15:22  mysql.ibd
-rw-r-----  1 mysql root 12582912 Jul 22 15:22  ibdata1
-rw-r-----  1 mysql root   196608 Jul 22 15:22 '#ib_16384_0.dblwr'
-rw-r-----  1 mysql root     1684 Jul 22 15:32  mysqld.log-20210725.gz
-rw-r-----  1 mysql root        1 Jul 27 13:48  binlog.index
drwxr-xr-x 11 mysql root     4096 Jul 27 16:05  ..
drwxr-x---  7 mysql root     4096 Jul 28 09:52  .
-rw-r-----  1 mysql root   181949 Jul 28 09:52  mysqld.log
1 Like

Hi @judith.agundez,

Thanks for the info. The permissions you shared look fine to me, and I can’t see the error message you mentioned in the MySQL logs. I’m seeing a different error though

2021-07-28T09:52:56.568191Z 0 [System] [MY-010116] [Server] /opt/bitnami/mysql/bin/mysqld.bin (mysqld 8.0.23) starting as process 30427
2021-07-28T09:52:56.577983Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2021-07-28T09:52:58.430395Z 1 [ERROR] [MY-013183] [InnoDB] Assertion failure: fil0fil.cc:10815:initial_fsize == (file->size * phy_page_size) thread 140514239231744
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/8.0/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
09:52:58 UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Thread pointer: 0x695dd40
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 = 7fcc0550aca0 thread_stack 0x46000
/opt/bitnami/mysql/bin/mysqld.bin(my_print_stacktrace(unsigned char const*, unsigned long)+0x2e) [0x2066f1e]
/opt/bitnami/mysql/bin/mysqld.bin(handle_fatal_signal+0x323) [0x1032cc3]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12730) [0x7fcc126a9730]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x10b) [0x7fcc113c07bb]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x121) [0x7fcc113ab535]
/opt/bitnami/mysql/bin/mysqld.bin() [0xdae42c]
/opt/bitnami/mysql/bin/mysqld.bin(fil_tablespace_redo_extend(unsigned char*, unsigned char const*, page_id_t const&, unsigned long, bool)+0x50b) [0x24828db]
/opt/bitnami/mysql/bin/mysqld.bin() [0x21f8614]
/opt/bitnami/mysql/bin/mysqld.bin() [0x21fa119]
/opt/bitnami/mysql/bin/mysqld.bin(recv_recovery_from_checkpoint_start(log_t&, unsigned long)+0x2106) [0x21fee36]
/opt/bitnami/mysql/bin/mysqld.bin(srv_start(bool)+0x1cd1) [0x22e84c1]
/opt/bitnami/mysql/bin/mysqld.bin() [0x21539c7]
/opt/bitnami/mysql/bin/mysqld.bin(dd::bootstrap::DDSE_dict_init(THD*, dict_init_mode_t, unsigned int)+0x81) [0x1d66d31]
/opt/bitnami/mysql/bin/mysqld.bin(dd::upgrade_57::do_pre_checks_and_initialize_dd(THD*)+0x18b) [0x203181b]
/opt/bitnami/mysql/bin/mysqld.bin() [0x10e3cb8]
/opt/bitnami/mysql/bin/mysqld.bin() [0x25973dc]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3) [0x7fcc1269efa3]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f) [0x7fcc114824cf]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0): is an invalid pointer
Connection ID (thread ID): 1
Status: NOT_KILLED

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.

We have a guide to recover the MySQL database, can you check if it helps?

https://docs.bitnami.com/general/infrastructure/mysql/administration/recover-database-mysql/#mysql

In case it doesn’t, can you also check the suggested links in the error above?

http://dev.mysql.com/doc/refman/8.0/en/forcing-innodb-recovery.html

1 Like

Hello @gongomgra,

Unfortunately, it doesn’t work. I managed to get through all “permission errors” and got innodb_force_recovery up to number 3.
Still crashes.

2021-07-30T16:05:10.688271Z 0 [System] [MY-010116] [Server] /opt/bitnami/mysql/bin/mysqld.bin (mysqld 8.0.23) starting as process 25257
2021-07-30T16:05:10.698894Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.

2021-07-30T16:05:12.181726Z 1 [ERROR] [MY-013183] [InnoDB] Assertion failure: fil0fil.cc:10815:initial_fsize == (file->size * phy_page_size) thread 139745384331008
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/8.0/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
16:05:12 UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Thread pointer: 0x71f85f0
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 = 7f1901fdeca0 thread_stack 0x46000
/opt/bitnami/mysql/bin/mysqld.bin(my_print_stacktrace(unsigned char const*, unsigned long)+0x2e) [0x2066f1e]
/opt/bitnami/mysql/bin/mysqld.bin(handle_fatal_signal+0x323) [0x1032cc3]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12730) [0x7f190f17d730]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x10b) [0x7f190de947bb]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x121) [0x7f190de7f535]
/opt/bitnami/mysql/bin/mysqld.bin() [0xdae42c]
/opt/bitnami/mysql/bin/mysqld.bin(fil_tablespace_redo_extend(unsigned char*, unsigned char const*, page_id_t const&, unsigned long, bool)+0x50b) [0x24828db]
/opt/bitnami/mysql/bin/mysqld.bin() [0x21f8614]
/opt/bitnami/mysql/bin/mysqld.bin() [0x21fa119]
/opt/bitnami/mysql/bin/mysqld.bin(recv_recovery_from_checkpoint_start(log_t&, unsigned long)+0x2106) [0x21fee36]
/opt/bitnami/mysql/bin/mysqld.bin(srv_start(bool)+0x1cd1) [0x22e84c1]
/opt/bitnami/mysql/bin/mysqld.bin() [0x21539c7]
/opt/bitnami/mysql/bin/mysqld.bin(dd::bootstrap::DDSE_dict_init(THD*, dict_init_mode_t, unsigned int)+0x81) [0x1d66d31]
/opt/bitnami/mysql/bin/mysqld.bin(dd::upgrade_57::do_pre_checks_and_initialize_dd(THD*)+0x18b) [0x203181b]
/opt/bitnami/mysql/bin/mysqld.bin() [0x10e3cb8]
/opt/bitnami/mysql/bin/mysqld.bin() [0x25973dc]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3) [0x7f190f172fa3]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f) [0x7f190df564cf]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0): is an invalid pointer
Connection ID (thread ID): 1
Status: NOT_KILLED

Support bundle: d230dcb9-c6ef-5694-df9c-7997286e23d8

1 Like

Hi @judith.agundez

Unfortunately, it doesn’t work. I managed to get through all “permission errors” and got innodb_force_recovery up to number 3.
Still crashes.

I am sorry to hear that! Do you happen to have a backup of your DB prior to this error? Maybe an easy and feasible option could simply be returning to that point.

If that is not possible, let me mention that according to MySQL’s Forcing InnoDB Recovery page, innodb_force_recovery can go all the way up to 6. You can give a try to those higher values just in case, but bear in mind that it is strongly advisable to have created a backup of your server beforehand just in case something gets even more corrupted.

Lastly, the error trace also mentions a guide that can be helpful in further debugging (or even reporting) such issues. I think it should be worth checking that guide if you haven’t already:

https://dev.mysql.com/doc/refman/8.0/en/crashing.html

Best regards,
Jose Antonio Carmona


Was my answer helpful? Click on :heart:

1 Like

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