Page MenuHomePhabricator

db2076, db2074 and db1123 crashed while altering templatelinks table
Closed, ResolvedPublic

Description

While attempting to ALTER T300775, it looks like we hit this bug: https://jira.mariadb.org/browse/MDEV-22627
db2076 has crashed several times, so it needs to be rebuilt.

db2076 is also sanitarium master in s6, so we should also reclone db2095:3316 and sanitize it.

  • Reclone db2076 (from db2124)
  • Reclone db2095:3316
  • Sanitize db2095:3316
  • Check private data on db2095:3316

Update
Later on db2074 and db1123 (s3 also crashed) which prompted to open https://jira.mariadb.org/browse/MDEV-27852

Event Timeline

Marostegui moved this task from Triage to In progress on the DBA board.

Change 761226 had a related patch set uploaded (by Marostegui; author: Marostegui):

[operations/puppet@production] db2076,db2095: Disable notifications

https://gerrit.wikimedia.org/r/761226

Change 761226 merged by Marostegui:

[operations/puppet@production] db2076,db2095: Disable notifications

https://gerrit.wikimedia.org/r/761226

I have recloned db2076 and I have been able to select fine on the templatelinks table (which got the new column as a result of the cloning from db2124)

I am now using db2076 to reclone db2095:3316

I have fixed and checked db2095:3316.
Tried to reproduce the bug after the data was fresh recloned on db2076 but I wasn't able to do so. If this is a real bug with compressed + 10.4.22 + other combination it will show up on more hosts as we keep progressing with T300775.
I commented on https://jira.mariadb.org/browse/MDEV-22627 and I was encouraged to open a new bug for this particular statement (ALTER), but as I have not been able to reproduce it after we recloned the host, I am going to leave it for now.

Not closing this until db2095:3316 has caught up and I have reenabled notifications on these two hosts.

Notifications reenabled, all host in sync

db2074 has crashed with the same error, so I am filing a mariadb bug for this as requested by Marko on the above ticket.

Change 762875 had a related patch set uploaded (by Marostegui; author: Marostegui):

[operations/puppet@production] db2074,db2094: Disable notifications

https://gerrit.wikimedia.org/r/762875

Change 762875 merged by Marostegui:

[operations/puppet@production] db2074,db2094: Disable notifications

https://gerrit.wikimedia.org/r/762875

Marostegui renamed this task from db2076 crashed to db2076, db2074 and db1123 crashed while altering templatelinks table.Feb 16 2022, 6:15 AM
Marostegui reopened this task as Open.
Marostegui updated the task description. (Show Details)

There's an update on these crashes. Last night (EU time) I opened https://jira.mariadb.org/browse/MDEV-27852 after seeing the crash of db2074 and having a clear way to reproduce the error (simply by starting replication as the alter was coming from the master). The host would crash as soon as it being to execute the alter statement for aawiki.templatelinks.

I approached Marko Mäkelä from MariaDB who happened to be online at the time. My idea was to ask them if they'd need some more information to be able to troubleshoot the issue, which was slightly different from https://jira.mariadb.org/browse/MDEV-22627. He was amazingly fast in responding and started to live debug with me.

These are the stacktraces that I generated for him:

(gdb) bt
#0  0x00007ffff7683ce1 in raise () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007ffff766d537 in abort () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x0000555555b0d67a in ut_dbg_assertion_failed (expr=expr@entry=0x5555565d00d0 "dict_tf2_is_valid(flags, flags2)", file=file@entry=0x5555565d0098 "/root/mariadb-10.4.22/storage/innobase/dict/dict0mem.cc", line=line@entry=152) at /root/mariadb-10.4.22/storage/innobase/ut/ut0dbg.cc:60
#3  0x0000555555b208c7 in dict_mem_table_create (name=name@entry=0x7f9efc020e18 "aawiki/#sql-329474_f", space=space@entry=0x0, n_cols=5, n_v_cols=n_v_cols@entry=0, flags=flags@entry=9, flags2=flags2@entry=80) at /root/mariadb-10.4.22/storage/innobase/dict/dict0mem.cc:152
#4  0x000055555602a31f in prepare_inplace_alter_table_dict (ha_alter_info=0x7fff9c2e9e30, altered_table=0x7fff9c2e9ed0, old_table=0x7f9efc017e58, table_name=0x7f9efc0156cf "templatelinks", flags=9, flags2=80, fts_doc_id_col=<optimized out>, add_fts_doc_id=<optimized out>, add_fts_doc_id_idx=<optimized out>) at /root/mariadb-10.4.22/storage/innobase/handler/handler0alter.cc:6479
#5  0x000055555602df18 in ha_innobase::prepare_inplace_alter_table (this=<optimized out>, altered_table=<optimized out>, ha_alter_info=<optimized out>) at /root/mariadb-10.4.22/storage/innobase/handler/ha_innodb.h:698
#6  0x0000555555cbd7e8 in mysql_inplace_alter_table (thd=0x7f9efc001538, table_list=0x7f9efc00c768, table=0x7f9efc017e58, altered_table=0x7fff9c2e9ed0, ha_alter_info=0x7fff9c2e9e30, alter_ctx=0x7fff9c2eb6e0, target_mdl_request=<optimized out>) at /root/mariadb-10.4.22/sql/sql_table.cc:7787
#7  0x0000555555cca384 in mysql_alter_table (thd=thd@entry=0x7f9efc001538, new_db=new_db@entry=0x7f9efc005b50, new_name=new_name@entry=0x7f9efc005f78, create_info=create_info@entry=0x7fff9c2ec2d0, table_list=<optimized out>, table_list@entry=0x7f9efc00c768, alter_info=alter_info@entry=0x7fff9c2ec210, order_num=0, order=0x0, ignore=false) at /root/mariadb-10.4.22/sql/sql_table.cc:10253
#8  0x0000555555d238b7 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x7f9efc001538) at /root/mariadb-10.4.22/sql/sql_alter.cc:520
#9  0x0000555555c23e6f in mysql_execute_command (thd=0x7f9efc001538) at /root/mariadb-10.4.22/sql/sql_parse.cc:6192
#10 0x0000555555c25e13 in mysql_parse (thd=0x7f9efc001538, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7fff9c2ee430, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /root/mariadb-10.4.22/sql/sql_parse.cc:7995
#11 0x0000555555f59a26 in Query_log_event::do_apply_event (this=0x7f9efc014b08, rgi=0x7f9efc000c40, query_arg=0x7f9efc014c45 "ALTER TABLE templatelinks ADD  tl_target_id BIGINT UNSIGNED DEFAULT NULL", q_len_arg=<optimized out>) at /root/mariadb-10.4.22/sql/sql_class.h:221
#12 0x0000555555b6db04 in Log_event::apply_event (rgi=0x7f9efc000c40, this=<optimized out>) at /root/mariadb-10.4.22/sql/log_event.h:1492
#13 apply_event_and_update_pos_apply (ev=ev@entry=0x7f9efc014b08, thd=thd@entry=0x7f9efc001538, rgi=rgi@entry=0x7f9efc000c40, reason=<optimized out>) at /root/mariadb-10.4.22/sql/slave.cc:3807
#14 0x0000555555b75d23 in apply_event_and_update_pos (ev=ev@entry=0x7f9efc014b08, thd=thd@entry=0x7f9efc001538, rgi=rgi@entry=0x7f9efc000c40) at /root/mariadb-10.4.22/sql/slave.cc:3969
#15 0x0000555555b77a22 in exec_relay_log_event (serial_rgi=0x7f9efc000c40, rli=0x555742283e68, thd=0x7f9efc001538) at /root/mariadb-10.4.22/sql/slave.cc:4288
#16 handle_slave_sql (arg=arg@entry=0x5557422824a0) at /root/mariadb-10.4.22/sql/slave.cc:5462
#17 0x0000555556333482 in pfs_spawn_thread (arg=0x7f9f2c011938) at /root/mariadb-10.4.22/storage/perfschema/pfs.cc:1869
#18 0x00007ffff7b2eea7 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#19 0x00007ffff7745def in clone () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) frame 4
#4 0x000055555602a31f in prepare_inplace_alter_table_dict (ha_alter_info=0x7fff9c5c2e30, altered_table=0x7fff9c5c2ed0, old_table=0x7f9f0c0185a8, table_name=0x7f9f0c0164cf "templatelinks", flags=9, flags2=80, fts_doc_id_col=<optimized out>, add_fts_doc_id=<optimized out>, add_fts_doc_id_idx=<optimized out>) at /root/mariadb-10.4.22/storage/innobase/handler/handler0alter.cc:6479
6479 /root/mariadb-10.4.22/storage/innobase/handler/handler0alter.cc: No such file or directory.


(gdb) print *user_table
$1 = {id = 185034, id_hash = 0x0, name = {m_name = 0x7f9f0c013a10 "aawiki/templatelinks", static part_suffix = "#P#"}, name_hash = 0x0, heap = 0x7f9f0c016ce0, data_dir_path = 0x0, space = 0x55573db615e0, space_id = 185029, flags = 1, flags2 = 80, skip_alter_undo = 0, file_unreadable = 0, cached = 1, to_be_dropped = 0, n_def = 7, n_cols = 7, n_t_cols = 7, n_t_def = 7, n_v_def = 0, n_v_cols = 0, persistent_autoinc = 0, can_be_evicted = 1, corrupted = 0, drop_aborted = 0, cols = 0x7f9f0c01a1b8, v_cols = 0x7f9f0c01a298, s_cols = 0x0, instant = 0x0, col_names = 0x7f9f0c01a2f0 "tl_from", v_col_names = 0x0, vers_start = 0, vers_end = 0, is_system_db = false, dict_frm_mismatch = DICT_FRM_CONSISTENT, fts_doc_id_index = 0x0, indexes = {count = 3, start = 0x7f9f0c01afe8, end = 0x7f9f0c023fa8, node = &dict_index_t::indexes}, freed_indexes = {count = 0, start = 0x0, end = 0x0, node = &dict_index_t::indexes}, foreign_list = {count = 0, start = 0x0, end = 0x0, node = &dict_foreign_t::heap}, referenced_list = {count = 0, start = 0x0, end = 0x0, node = &dict_foreign_t::heap}, table_LRU = {prev = 0x7f9f4800da78, next = 0x7f9f24007878}, fk_max_recusive_level = 0, n_foreign_key_checks_running = {m_counter = {<std::__atomic_base<int>> = {static _S_alignment = 4, _M_i = 0}, <No data fields>}}, query_cache_inv_trx_id = 0, def_trx_id = 0, foreign_set = std::set with 0 elements, referenced_set = std::set with 0 elements, stat_initialized = 1, stats_last_recalc = 0, stat_persistent = 0, stats_auto_recalc = 0, stats_sample_pages = 0, stat_n_rows = 306, stat_clustered_index_size = 1, stat_sum_of_other_index_sizes = 3, stat_modified_counter = 0, stats_bg_flag = 0 '\000', stats_error_printed = false, autoinc_lock = 0x7f9f0c01a298, autoinc_mutex = {<std::__mutex_base> = {_M_mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}}, <No data fields>}, autoinc = 0, n_waiting_or_granted_auto_inc_locks = 0, autoinc_trx = 0x0, fts = 0x0, quiesce = QUIESCE_NONE, n_rec_locks = 0, n_ref_count = {m_counter = {<std::__atomic_base<unsigned int>> = {static _S_alignment = 4, _M_i = 1}, <No data fields>}}, locks = {count = 0, start = 0x0, end = 0x0, node = &lock_table_t::locks}, update_time = 0, vc_templ = 0x0}

This was the table at the time:

root@db2074.codfw.wmnet[aawiki]> show create table templatelinks;
+---------------+----------------------------------------------------------------------------------------------------------------------
| Table         | Create Table
+---------------+----------------------------------------------------------------------------------------------------------------------
| templatelinks | CREATE TABLE `templatelinks` (
  `tl_from` int(8) unsigned NOT NULL DEFAULT 0,
  `tl_namespace` int(11) NOT NULL DEFAULT 0,
  `tl_title` varbinary(255) NOT NULL DEFAULT '',
  `tl_from_namespace` int(11) NOT NULL DEFAULT 0,
  PRIMARY KEY (`tl_from`,`tl_namespace`,`tl_title`),
  KEY `tl_namespace` (`tl_namespace`,`tl_title`,`tl_from`),
  KEY `tl_backlinks_namespace` (`tl_from_namespace`,`tl_namespace`,`tl_title`,`tl_from`)
) ENGINE=InnoDB DEFAULT CHARSET=binary ROW_FORMAT=COMPRESSED KEY_BLOCK_SIZE=8

And the show table status at the time

| templatelinks                | InnoDB |      10 | Compact    |   306 |             53 |       16384 |                0 |        49152 |         0 |           NULL | 2022-02-01 08:35:54 | NULL                | NULL                | binary    |     NULL | row_format=COMPRESSED key_block_size=8 |         |                0 | N         |

Marko noticed that the table had a mismatch where InnoDB thinks that the table was ROW_FORMAT=COMPACT (the default between MySQL 5.0.3 and MySQL 5.7.8), while the .frm file says it was ROW_FORMAT=COMPRESSED. This was causing the issue.
Marko's thoughts were that this table probably was created when the setting innodb_file_format=antelope was in effect, and thus the creation of COMPRESSED or DYNAMIC tables was forbidden. This setting was deprecated and ignored in MySQL 5.7 and MariaDB 10.2.
This is certainly possible as these wikis are super old and were probably created lots of years ago, even before 10.0 I would say.

Looking at the host, db2074, I noticed that this mismatch was present in more than 800 wikis.

The workaround was to rebuild this table with ROW_FORMAT=COMPRESSED which I left running last night and just completed (and now running via replication on the sanitarium host). I have confirmed there are no more mismatches for templatelinks, so this workaround has worked and the schema change is now going thru.

db1123 crashed last night while attempting to run the schema change, and I just confirmed there are around 100 wikis with that issue was well - which I am rebuilding as we speak.

We should probably go thru all the hosts on a section (especially masters) before attempting to run this change to make sure we don't have mismatches, and if we do, we should rebuild the tables first. I have seen pagelinks table in some of the outputs of show table status, so that is likely to be an issue as well if we need to alter that one at some point.

This is probably also what caused the crash on db2076 although we cannot reproduce it anymore as the host was recloned.

Marko is usually super fast when replying to tickets, but last night he was amazing, super helpful, friendly and spent more than an hour live troubleshooting with me on the mariadb zulip until the issue was found and the workaround was provided.

Change 763183 had a related patch set uploaded (by Marostegui; author: Marostegui):

[operations/software/schema-changes@master] add_tl_target_id_T300775.py: Add ALGORITHM=COPY

https://gerrit.wikimedia.org/r/763183

Change 763183 merged by jenkins-bot:

[operations/software/schema-changes@master] add_tl_target_id_T300775.py: Add ALGORITHM=COPY

https://gerrit.wikimedia.org/r/763183

Let me be sure I got this right:

  • there could be some tables where the real and exposed format mismatch?
  • It can be detected just by looking at information_schema.tables (ROW_FORMAT and CREATE OPTIONS columns)? For example, this query: select * FROM information_schema.tables where CREATE_OPTIONS like '%COMPRESSED%' and ROW_FORMAT <> 'COMPRESSED' limit 10; and this for old InnoDB table versions: select * FROM information_schema.tables where engine = 'InnoDB' AND ROW_FORMAT NOT IN ('Compressed', 'Dynamic') and TABLE_SCHEMA like '%wik%';
  • And if present and the db can be get down/stop replication, we can rebuild the table with "ALTER TABLE X ROW_FORMAT=COMPRESSED"?

Asking to check and identify it on at least the backup sources.

Let me be sure I got this right:

  • there could be some tables where the real and exposed format mismatch?

Correct

  • It can be detected just by looking at information_schema.tables (ROW_FORMAT and CREATE OPTIONS columns)? For example, this query: select * FROM information_schema.tables where CREATE_OPTIONS like '%COMPRESSED' and ROW_FORMAT <> 'COMPRESSED' limit 10;

Basically looking Compact and ROW_FORMAT=COMPRESSED in show table status. It should say Compressed for ROW_FORMAT=COMPRESSED.

  • And if present and the db can be get down/stop replication, we can rebuild the table with "ALTER TABLE X ROW_FORMAT=COMPRESSED"?

No need to worry/work from your side. As I need to execute the schema change on all the hosts, I have added ALGORITHM=COPY to the schema change, so that fixes it while running it. It has been tested on two hosts and it all went fine so I am deploying it now.

Check the second snippet I edited in, I think those should return non dynamic or compressed innodb & mediawiki tables. While they will not require to be converted for this bug, probably they should disappear in the future to avoid future problems.

Check the second snippet I edited in, I think those should return non dynamic or compressed innodb & mediawiki tables. While they will not require to be converted for this bug, probably they should disappear in the future to avoid future problems.

Agreed

I am going to close this as resolved as I have created follow up tasks to fix the other tables:
T301848 T302222