David A. Windham
david
/
til
1
0
Fork 0
Files
Tree: c83559efa6
Branches Tags
til
/
posts
/
2024-07-10-posts.md

2024-07-10-posts.md 8.6 KB
History Raw

draft: true title: MariaDB Meltdown slug: mariadb-meltdown description: Today I learned how to fix some seriously corrupted database tables in MariaDB. <!--- authors:

Today I learned how to fix some seriously corrupted database tables in MariaDB.

I had a serialized data issue with a search & replace script I use to migrate databases back and forth from staging servers, so I reverted to the command line to make the changes. As is usually the case when something breaks, I tend to take a break myself. I shut down the machine to walk the dog and when I booted back up, MariaDB wasn't starting. Originally thought it might be related to some sort of permissions issue with Homebrew so I checked my plist files and tried running them as sudo to no avail.

launchctl unload -w ~/Library/LaunchAgents/homebrew.mxcl.mariadb.plist
launchctl load -w ~/Library/LaunchAgents/homebrew.mxcl.mariadb.plist

I checked the logs @ /opt/homebrew/var/mysql/ovid.local.err and found:

2024-07-09 15:55:41 mysqld_safe Starting mariadbd daemon with databases from /opt/homebrew/var/mysql
2024-07-09 15:55:41 0 [Note] Starting MariaDB 11.4.2-MariaDB source revision 3fca5ed772fb75e3e57c507edef2985f8eba5b12 as process 745
2024-07-09 15:55:41 0 [Warning] Setting lower_case_table_names=2 because file system for /opt/homebrew/var/mysql/ is case insensitive
2024-07-09 15:55:42 0 [Note] InnoDB: Compressed tables use zlib 1.2.12
2024-07-09 15:55:42 0 [Note] InnoDB: Number of transaction pools: 1
2024-07-09 15:55:42 0 [Note] InnoDB: Using generic crc32 instructions
2024-07-09 15:55:42 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
2024-07-09 15:55:42 0 [Note] InnoDB: Completed initialization of buffer pool
2024-07-09 15:55:42 0 [Note] InnoDB: Resetting space id's in the doublewrite buffer
2024-07-09 15:55:42 0 [ERROR] InnoDB: Missing FILE_CHECKPOINT(2511633256) at 2511633256
2024-07-09 15:55:42 0 [ERROR] InnoDB: Log scan aborted at LSN 2511633256
2024-07-09 15:55:42 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
2024-07-09 15:55:42 0 [Note] InnoDB: Starting shutdown...
2024-07-09 15:55:42 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2024-07-09 15:55:42 0 [Note] Plugin 'FEEDBACK' is disabled.
2024-07-09 15:55:42 0 [Note] Plugin 'wsrep-provider' is disabled.
2024-07-09 15:55:42 0 [ERROR] Unknown/unsupported storage engine: InnoDB
2024-07-09 15:55:42 0 [ERROR] Aborting

At this point, I'm hitting stack overflow and trying to reverse-engineer my last steps. I start adding in InnoDB recovery modes @ /opt/homebrew/etc/my.cnf' and find that the only level that will start it up is 6

innodb_force_recovery=6

This is the warning from the MySQL documentation for level 6

"This value can permanently corrupt data files. Leaves database pages in an obsolete state, which in turn may introduce more corruption into B-trees and other database structures. Sets InnoDB to read-only."

but I'm able to go ahead and run a full mysqldump coming in at a meager 18GB. Because I know this will be a process I let it rest for the evening knowing I'd be better off picking back up on it with a fresh cup of coffee ☕️ in the morning.

2024-07-10  9:52:47 0 [Note] Starting MariaDB 11.4.2-MariaDB source revision 3fca5ed772fb75e3e57c507edef2985f8eba5b12 as process 97176
2024-07-10  9:52:47 0 [Warning] Setting lower_case_table_names=2 because file system for /opt/homebrew/var/mysql/ is case insensitive
2024-07-10  9:52:47 0 [Note] InnoDB: !!! innodb_force_recovery is set to 6 !!!
2024-07-10  9:52:47 0 [Note] InnoDB: Started in read only mode
2024-07-10  9:52:47 0 [Note] InnoDB: Compressed tables use zlib 1.2.12
2024-07-10  9:52:47 0 [Note] InnoDB: Number of transaction pools: 1
2024-07-10  9:52:47 0 [Note] InnoDB: Using generic crc32 instructions
2024-07-10  9:52:47 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
2024-07-10  9:52:47 0 [Note] InnoDB: Completed initialization of buffer pool
2024-07-10  9:52:47 0 [Note] InnoDB: innodb_force_recovery=6 skips redo log apply
2024-07-10  9:52:47 0 [Note] InnoDB: innodb_force_recovery=6 skips redo log apply
2024-07-10  9:52:47 0 [Note] InnoDB: log sequence number 0; transaction id 0
2024-07-10  9:52:47 0 [Note] Plugin 'FEEDBACK' is disabled.
2024-07-10  9:52:47 0 [Note] Plugin 'wsrep-provider' is disabled.
2024-07-10  9:52:48 0 [Note] Server socket created on IP: '::'.
2024-07-10  9:52:48 0 [Note] Server socket created on IP: '0.0.0.0'.
2024-07-10  9:52:48 0 [Note] mariadbd: Event Scheduler: Loaded 0 events
2024-07-10  9:52:48 0 [Note] /opt/homebrew/opt/mariadb/bin/mariadbd: ready for connections.

I crank up MySQL in recovery mode again to check this logs and I'm getting errors on the hist_type and histogram tables.

2024-07-10  9:53:00 3 [ERROR] Incorrect definition of table mysql.column_stats: expected column 'hist_type' at position 9 to have type enum('SINGLE_PREC_HB','DOUBLE_PREC_HB','JSON_HB'), found type enum('SINGLE_PREC_HB','DOUBLE_PREC_HB').
2024-07-10  9:53:00 3 [ERROR] Incorrect definition of table mysql.column_stats: expected column 'histogram' at position 10 to have type longblob, found type varbinary(255).

I dug through a bit of documents to alter this tables but unfortunately I was only able to get it running in a read-only recovery mode and these wouldn't work.

ALTER TABLE mysql.column_stats MODIFY histogram longblob;
ALTER TABLE mysql.column_stats MODIFY hist_type enum('SINGLE_PREC_HB','DOUBLE_PREC_HB','JSON_HB');

At this point I kinda knew the best option would be the ole' restart or reinstall. I decided to wipe it clean and reinstall the databases. Luckily I was able to knock it out within a couple hours 🙌🏼 and it's back up and running.

240710 11:14:32 mysqld_safe Starting mariadbd daemon with databases from /opt/homebrew/var/mysql
2024-07-10 11:14:32 0 [Note] Starting MariaDB 11.4.2-MariaDB source revision 3fca5ed772fb75e3e57c507edef2985f8eba5b12 as process 55269
2024-07-10 11:14:32 0 [Warning] Setting lower_case_table_names=2 because file system for /opt/homebrew/var/mysql/ is case insensitive
2024-07-10 11:14:32 0 [Note] InnoDB: Compressed tables use zlib 1.2.12
2024-07-10 11:14:32 0 [Note] InnoDB: Number of transaction pools: 1
2024-07-10 11:14:32 0 [Note] InnoDB: Using generic crc32 instructions
2024-07-10 11:14:32 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
2024-07-10 11:14:32 0 [Note] InnoDB: Completed initialization of buffer pool
2024-07-10 11:14:32 0 [Note] InnoDB: End of log at LSN=47610
2024-07-10 11:14:32 0 [Note] InnoDB: Opened 3 undo tablespaces
2024-07-10 11:14:32 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active.
2024-07-10 11:14:32 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
2024-07-10 11:14:32 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
2024-07-10 11:14:32 0 [Note] InnoDB: log sequence number 47610; transaction id 14
2024-07-10 11:14:32 0 [Note] Plugin 'FEEDBACK' is disabled.
2024-07-10 11:14:32 0 [Note] Plugin 'wsrep-provider' is disabled.
2024-07-10 11:14:32 0 [Note] InnoDB: Loading buffer pool(s) from /opt/homebrew/var/mysql/ib_buffer_pool
2024-07-10 11:14:32 0 [Note] InnoDB: Buffer pool(s) load completed at 240710 11:14:32
2024-07-10 11:14:32 0 [Note] Server socket created on IP: '::'.
2024-07-10 11:14:32 0 [Note] Server socket created on IP: '0.0.0.0'.
2024-07-10 11:14:32 0 [Note] mariadbd: Event Scheduler: Loaded 0 events
2024-07-10 11:14:32 0 [Note] /opt/homebrew/opt/mariadb/bin/mariadbd: ready for connections.
Version: '11.4.2-MariaDB'  socket: '/tmp/mysql.sock'  port: 3306  Homebrew

🔥 NOTE: I should remember to do a little housecleaning more often though because I found some other loose ends in my homebrew packages. And this reminded me about every previous time I've had to debug an error with MySQL and about my favorite video on the topic 👇🏼