2

Yesterday I updated my Wordpress website to the latest version of WordPress (6.0), and I updated several other plugins to their latest versions. After the updates everything appeared to be working fine, so I disabled my maintenance page. Several hours later my remote MySQL server (used for the WP database) crashed and this morning my WebServer (Nginx) couldn’t connect to the database.

I restored my production servers from backup, and I’ve attached the potentially corrupted volume from the MySQL server to a new instance. MySQL won’t start, and I’ve been reviewing the logs, but they are well above my level of expertise.

Below are two sections of the logs. The first describes potential corruption? I added innodb_force_recovery = 6 to my CNF file and that allows the MySQL to start, but I don’t really know what this means. Does that mean there is a 100% guarantee of corruption and if so, how would I find out the cause / where?

The second section has a buffer pool error, which is a little easier for me to understand. I commented out my innodb_buffer_pool_size setting in my CNF file, but that had no affect on MySQL starting without innodb_force_recovery set to 6.

I’m hoping someone can explain the errors and potentially how to find out the cause/s?

MySQL8.0.29 R6G.Large (2 cores, 16gb ram) Buffer pool: 12000M

Section 1:

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.
18:49:04 UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Thread pointer: 0xfffc28000b20
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 = fffc488565f0 thread_stack 0x100000
/usr/sbin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x44) [0x1d0e2a4]
/usr/sbin/mysqld(print_fatal_signal(int)+0x28c) [0xe3278c]
/usr/sbin/mysqld(my_server_abort()+0xa0) [0xe32920]
/usr/sbin/mysqld(my_abort()+0x14) [0x1d08244]
/usr/sbin/mysqld(ut_dbg_assertion_failed(char const*, char const*, unsigned long)+0x290) [0x1f79ba0]
/usr/sbin/mysqld() [0x1f7c42c]
/usr/sbin/mysqld(page_copy_rec_list_end_no_locks(buf_block_t*, buf_block_t*, unsigned char*, dict_index_t*, mtr_t*)+0x2dc) [0x1ec1dec]
/usr/sbin/mysqld(page_copy_rec_list_end(buf_block_t*, buf_block_t*, unsigned char*, dict_index_t*, mtr_t*)+0x300) [0x1ec2270]
/usr/sbin/mysqld(btr_compress(btr_cur_t*, bool, mtr_t*)+0x624) [0x1fa53f4]
/usr/sbin/mysqld(btr_cur_pessimistic_delete(dberr_t*, bool, btr_cur_t*, unsigned int, bool, unsigned long, unsigned long, unsigned long, mtr_t*, btr_pcur_t*, purge_node_t*)+0x1cc) [0x1fb130c]
/usr/sbin/mysqld() [0x1f02bf8]
/usr/sbin/mysqld(row_purge_step(que_thr_t*)+0x4f4) [0x1f05364]
/usr/sbin/mysqld(que_run_threads(que_thr_t*)+0x578) [0x1ece5e8]
/usr/sbin/mysqld(srv_worker_thread()+0x21c) [0x1f3184c]
/usr/sbin/mysqld(std::thread::_State_impl<std::thread::_Invoker<std::tuple<Detached_thread, void (*)()> > >::_M_run()+0xd4) [0x1e85774]
/usr/sbin/mysqld() [0x244623c]
/lib64/libpthread.so.0(+0x722c) [0xffffab1ec22c]
/lib64/libc.so.6(+0xd2e5c) [0xffffaaa99e5c]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0): Connection ID (thread ID): 0
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.
2022-05-25T18:49:04.565524Z 0 [Warning] [MY-010918] [Server] 'default_authentication_plugin' is deprecated and will be removed in a future release. Please use authentication_policy instead.
2022-05-25T18:49:04.565544Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.29) starting as process 6679
2022-05-25T18:49:04.571539Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-05-25T18:49:05.807854Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2022-05-25T18:49:06.622221Z 0 [System] [MY-010229] [Server] Starting XA crash recovery...
2022-05-25T18:49:06.625449Z 0 [System] [MY-010232] [Server] XA crash recovery finished.
2022-05-25T18:49:07.251794Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2022-05-25T18:49:07.251829Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2022-05-25T18:49:07.272581Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
2022-05-25T18:49:07.272631Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.29'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server - GPL.
2022-05-25T18:49:07.347411Z 0 [ERROR] [MY-012687] [InnoDB] [FATAL] Rec offset 99, cur1 offset 4038, cur2 offset 16004
2022-05-25T18:49:07.347449Z 0 [ERROR] [MY-013183] [InnoDB] Assertion failure: page0page.cc:502:ib::fatal triggered thread 281457662619536

Section 2:

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.
2022-05-26T12:27:29.518146Z 0 [Warning] [MY-010918] [Server] 'default_authentication_plugin' is deprecated and will be removed in a future release. Please use authentication_policy instead.
2022-05-26T12:27:29.518165Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.29) starting as process 17135
2022-05-26T12:27:29.524074Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-05-26T13:20:40.613066Z 0 [Warning] [MY-010918] [Server] 'default_authentication_plugin' is deprecated and will be removed in a future release. Please use authentication_policy instead.
2022-05-26T13:20:40.613087Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.29) starting as process 1086
2022-05-26T13:20:41.866918Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-05-26T13:20:49.824464Z 0 [Warning] [MY-012681] [InnoDB] page_aligned_alloc mmap(137232384 bytes) failed; errno 12
2022-05-26T13:20:49.844869Z 0 [Warning] [MY-012681] [InnoDB] page_aligned_alloc mmap(137232384 bytes) failed; errno 12
2022-05-26T13:20:49.961232Z 1 [ERROR] [MY-012956] [InnoDB] Cannot allocate memory for the buffer pool
2022-05-26T13:20:49.961279Z 1 [ERROR] [MY-012930] [InnoDB] Plugin initialization aborted with error Generic error.
2022-05-26T13:20:49.962080Z 1 [ERROR] [MY-010334] [Server] Failed to initialize DD Storage Engine
2022-05-26T13:20:49.962240Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2022-05-26T13:20:49.962355Z 0 [ERROR] [MY-010119] [Server] Aborting
2022-05-26T13:20:49.966630Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.29)  MySQL Community Server - GPL.

Any help would be great.

Update: I ran mysqlcheck on my faulty database and it found corruption. Looks like the cause is WooCommerce?

Here is the error mysqlcheck returns:

production.wp_wc_admin_note_actions
Warning  : InnoDB: The B-tree of index PRIMARY is corrupted.
Warning  : InnoDB: Index 'note_id' contains 1004 entries, should be 18446744073709551615.
error    : Corrupt

Jack

JackJohnstone53
  • 23
  • 4
  • File a bug at bugs.mysql.com -- I don't think WP is _directly_ at fault. Did anything else happen at the same time? Such as power failure, disk failure, etc? – Rick James May 27 '22 at 17:19
  • Hey Rick, Not that I’ve found. Everything else seems fine. Wouldn’t a bug have affected my backup too, which hasn’t had any issues? The affected volume has been running on a separate instance in recovery mode 6 for 24 hours and hasn’t had any further issues. Is there a way to find out if there is corrupted tables and or a cause? – JackJohnstone53 May 27 '22 at 17:42
  • "Above my paygrade" – Rick James May 27 '22 at 18:06
  • Mine too :) , hopefully another member will have some ideas. Thanks – JackJohnstone53 May 27 '22 at 18:13
  • @RickJames , it appears to be the WooCommerce update that caused the problem. I figured out how to use mysqlcheck, and it found corruption in wp_wc_admin_note_actions, see above, I updated my post. – JackJohnstone53 May 27 '22 at 20:05
  • Was the table Engine=MyISAM? That has corruption problems. Switch to InnoDB. – Rick James May 27 '22 at 20:12
  • It is innoDB, I’ve never used MyISAM. I’ve reached out to WooCommerce support and they are investigating. – JackJohnstone53 May 27 '22 at 20:34
  • Jack, Did you step through innodb_force_recovery=1 then 2 then 3 or go straight for 6? Stepping is the documented method for the most recoverable data with least amount of hazard. – Wilson Hauck May 29 '22 at 21:51
  • Wilson, no, I only read that documentation afterwards. I have full backups before the corruption, and I have a backup of the corrupted server prior to forced recovery. I’ve since restored the corrupted server from backup and recovery 1 didn’t restart, but 2 did. I still have not been able to narrow down the cause. WooCommerce said it’s not them and no one else has reported an issue. Any idea on how to find the cause? – JackJohnstone53 May 30 '22 at 10:42
  • 1
    We are sseing exactly the same issue. We are running around 300 MySQL 8.0.29 servers. In the past 2 1/2 weeks we have seen this issue on at least nine MySQL servers. It is almost always related to the table you have mentioned: wp_wc_admin_note_actions. That being said, we have also seen it on other tables as well. I have created a thread in the MySQL forums for this: https://forums.mysql.com/read.php?22,704532,704532#msg-704532 Unfortunately, I cannot reproduce the issue at all, although having tried a lot, it just seems to happen randomly, so far. – user40974 Jun 01 '22 at 10:45
  • 1
    @user40974 , very interesting! Have you only had the issue since upgrading WordPress or WooCommerce? I’m planning on duplicating my production environment and updating one by one, with 24 hours in between each update and checking the database for corruption before updating the next. WooCommerce seems to think it’s not them. I don’t think it’s MySQL, as my other MySQL databases running the same version, but not connected to WordPress etc haven’t had issues. – JackJohnstone53 Jun 01 '22 at 11:14
  • @JackJohnstone53 Unfortunately, I can only see this from an outside perspective, working as a systems administrator, so I usually only notice, when it is too late and I do not exactly know what our customers did before. It seems though that it is indeed usually connected to an upgrade of Woocommerce. But as already said, I have already seen this happen with other wordpress plugin tables as well, so my guess is, that is is a MySQL bug. A plugin should not be able to corrupt an InnoDB database, no matter how weird the data is it provides / modifies. It also started after the 8.0.29 upgrade. – user40974 Jun 01 '22 at 11:33
  • Another table where we had two cases of this is called "spbc_scan_results". That seems to be related to this wordpress plugin: https://de.wordpress.org/plugins/security-malware-firewall/ – user40974 Jun 01 '22 at 11:38
  • 1
    @user40974, I always thought a plugin could corrupt a database, but that’s above my level of competence. I’m going to followup with WooCommerce support and send them the links for the thread and your MySQL forum post. I’ll update the thread if I find anything. Thanks! – JackJohnstone53 Jun 01 '22 at 11:43
  • @user40974 , have you made any progress figuring out a cause or has MySQL commented on the bug submission? I haven’t had a chance to update plugins one by one, but I hope to at the end of the week. – JackJohnstone53 Jun 06 '22 at 14:33
  • @JackJohnstone53 Seems like the other users in the MySQL forum thread figured it out. I just posted an answer summing it up. – user40974 Jun 10 '22 at 15:03

1 Answers1

2

This issue was also reported in the MySQL community forums.

Shortly after it was first reported, several other MySQL 8.0.29 users responded, stating they faced similar issues, often related to the table wc_admin_note_actions of the Wordpress plugin Woocommerce.

Finally, an user was able to reproduce the issue and reported it in the MySQL bug tracker.

Unfortunately, the issue cannot be viewed. I can say from my own experience that this is due to the fact that the MySQL team sees issues resulting in crashes / data corruption as security issues and so hides them from the public in their bug tracker.

That being said, the final post by another user confirms that the reported issue was accepted by the MySQL team (so they were able to reproduce it).

According to this user, the issue can be prevented by running mysqlcheck -Ao on a system that was upgraded to MySQL 8.0.29, however, if there are already corrupted tables (and since it is silent corruption, you may only notice once accessing them), it will crash the MySQL server and you might have to recover using innodb_force_recovery or from backups.

According to the user who reproduced and reported the issue, it will be fixed in 8.0.30, which is the next MySQL Server version.

user40974
  • 170
  • 1
  • 7