--- draft: true title: MariaDB Meltdown slug: mariadb-meltdown description: Today I learned how to fix some seriously corrupted database tables in MariaDB. tags: [database, mysql, ovid] image: https://davidawindham.com/wp-content/themes/daw/img/opengraph_image.jpg hide_table_of_contents: true --- 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. ```sh 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: ```sh 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` ```sh 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. ```sh 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. ```sh 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. ```sh 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. ```sh 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 👇🏼