Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-35181

Assertion 'state < buf_page_t::READ_FIX' in buf_page_create_low()

    XMLWordPrintable

Details

    Description

      mleich produced a core dump with an assertion failure in buf_page_create_low(). The page state would be exactly buf_page_t::READ_FIX.

      ssh pluto
      marko@pluto:~$ gdb -c /data/results/1729078320/TBR-2190/1/data/core.2707264 /data/Server_bin/10.11-MDEV-34830_debug_Og/bin/mariadbd
      

      $2 = {id_ = {m_id = 0x33d}, hash = 0x0, oldest_modification_ = {m = std::atomic<unsigned long> = { 0x0 }}, lock = {lock = {writer = {lock = std::atomic<unsigned int> = { 0x3 }}, 
            readers = std::atomic<unsigned int> = { 0x80000000 }}, recursive = 0x1, writer = std::atomic<unsigned long> = { 0x7fcc93096640 }, readers_lock = {lock = std::atomic<unsigned int> = { 0x0 }}, 
          readers = std::atomic<std::__debug::unordered_multiset<unsigned long, std::hash<unsigned long>, std::equal_to<unsigned long>, std::allocator<unsigned long> > *> = { 0x7fcc6803c210 }}, 
        frame = 0x7fccc4c65000 "", zip = {data = 0x0, m_end = 0x0, m_nonempty = 0x0, n_blobs = 0x0, ssize = 0x0, m_start = 0x0, m_external = 0x0, fix = {m = std::atomic<unsigned int> = { 0x20000001 }}}, 
        in_zip_hash = 0x0, in_LRU_list = 0x1, in_page_hash = 0x1, in_free_list = 0x0, list = {prev = 0x0, next = 0x0}, LRU = {prev = 0x7fccc4cddd80, next = 0x7fccc4ddbea0}, old = 0x0, freed_page_clock = 0xa0f6, 
        access_time = {m_counter = std::atomic<unsigned int> = { 0x0 }}}
      

      The page looks like an undo log page that contained some records mentioning some names of auxiliary tables for FULLTEXT INDEX, and it was being created as an undo log page in a DDL, in an operation that involved FULLTEXT INDEX:

      #12 0x00007fccc7527e96 in __GI___assert_fail (assertion=0x55ddc901f680 "state < buf_page_t::READ_FIX", file=0x55ddc907c1b0 "/data/Server/10.11-MDEV-34830/storage/innobase/buf/buf0buf.cc", line=0xe4c, function=0x55ddc907cfd0 "buf_block_t* buf_page_create_low(page_id_t, ulint, mtr_t*, buf_block_t*)") at ./assert/assert.c:101
      #13 0x000055ddc89ed426 in buf_page_create_low (page_id=..., zip_size=zip_size@entry=0x0, mtr=mtr@entry=0x7fcc9308fa80, free_block=free_block@entry=0x7fccc4de06f0) at /data/Server/10.11-MDEV-34830/storage/innobase/buf/buf0buf.cc:3660
      #14 0x000055ddc89edc0d in buf_page_create (space=space@entry=0x55ddcbe878e0, offset=offset@entry=0x33d, zip_size=0x0, mtr=mtr@entry=0x7fcc9308fa80, free_block=free_block@entry=0x7fccc4de06f0) at /data/Server/10.11-MDEV-34830/storage/innobase/buf/buf0buf.cc:3823
      #15 0x000055ddc8ab7a53 in fsp_page_create (space=space@entry=0x55ddcbe878e0, offset=offset@entry=0x33d, mtr=mtr@entry=0x7fcc9308fa80) at /data/Server/10.11-MDEV-34830/storage/innobase/fsp/fsp0fsp.cc:1051
      #16 0x000055ddc8abba68 in fsp_alloc_free_page (space=space@entry=0x55ddcbe878e0, hint=<optimized out>, hint@entry=0x33d, mtr=mtr@entry=0x7fcc9308fa80, init_mtr=init_mtr@entry=0x7fcc9308fa80, err=err@entry=0x7fcc9308f9dc) at /data/Server/10.11-MDEV-34830/storage/innobase/fsp/fsp0fsp.cc:1175
      #17 0x000055ddc8abd4e7 in fseg_alloc_free_page_low (space=space@entry=0x55ddcbe878e0, seg_inode=seg_inode@entry=0x7fccc4e36272 "", iblock=0x7fccc4ddef60, hint=hint@entry=0x33d, direction=direction@entry=0x6f, has_done_reservation=has_done_reservation@entry=0x1, mtr=0x7fcc9308fa80, init_mtr=0x7fcc9308fa80, err=0x7fcc9308f9dc)
          at /data/Server/10.11-MDEV-34830/storage/innobase/fsp/fsp0fsp.cc:2159
      #18 0x000055ddc8abdcde in fseg_alloc_free_page_general (seg_header=<optimized out>, hint=0x33d, direction=direction@entry=0x6f, has_done_reservation=has_done_reservation@entry=0x1, mtr=mtr@entry=0x7fcc9308fa80, init_mtr=init_mtr@entry=0x7fcc9308fa80, err=0x7fcc9308f9dc) at /data/Server/10.11-MDEV-34830/storage/innobase/fsp/fsp0fsp.cc:2299
      #19 0x000055ddc897360d in trx_undo_add_page (undo=undo@entry=0x7fcc6f037650, mtr=mtr@entry=0x7fcc9308fa80, err=err@entry=0x7fcc9308f9dc) at /data/Server/10.11-MDEV-34830/storage/innobase/trx/trx0undo.cc:685
      #20 0x000055ddc894ad6d in trx_undo_report_row_operation (thr=thr@entry=0x7fcc6f054e20, index=index@entry=0x55ddcbefd680, clust_entry=clust_entry@entry=0x7fcc6f051580, update=update@entry=0x0, cmpl_info=cmpl_info@entry=0x0, rec=rec@entry=0x7fccc4e8ce40 "", offsets=<optimized out>, roll_ptr=<optimized out>) at /data/Server/10.11-MDEV-34830/storage/innobase/trx/trx0rec.cc:2023
      #21 0x000055ddc89b4b61 in btr_cur_del_mark_set_clust_rec (block=0x7fccc4de3540, rec=0x7fccc4e8ce40 "", index=index@entry=0x55ddcbefd680, offsets=offsets@entry=0x7fcc930902c0, thr=thr@entry=0x7fcc6f054e20, entry=0x7fcc6f051580, mtr=0x7fcc93090520) at /data/Server/10.11-MDEV-34830/storage/innobase/btr/btr0cur.cc:4488
      #22 0x000055ddc890ad79 in row_upd_del_mark_clust_rec (node=node@entry=0x7fcc6f053238, index=index@entry=0x55ddcbefd680, offsets=offsets@entry=0x7fcc930902c0, thr=thr@entry=0x7fcc6f054e20, referenced=referenced@entry=0x0, foreign=foreign@entry=0x0, mtr=0x7fcc93090520) at /data/Server/10.11-MDEV-34830/storage/innobase/row/row0upd.cc:2515
      #23 0x000055ddc890da5a in row_upd_clust_step (node=node@entry=0x7fcc6f053238, thr=thr@entry=0x7fcc6f054e20) at /data/Server/10.11-MDEV-34830/storage/innobase/row/row0upd.cc:2657
      #24 0x000055ddc890dfc2 in row_upd (node=node@entry=0x7fcc6f053238, thr=thr@entry=0x7fcc6f054e20) at /data/Server/10.11-MDEV-34830/storage/innobase/row/row0upd.cc:2779
      #25 0x000055ddc890e3dc in row_upd_step (thr=thr@entry=0x7fcc6f054e20) at /data/Server/10.11-MDEV-34830/storage/innobase/row/row0upd.cc:2921
      #26 0x000055ddc882983d in que_thr_step (thr=thr@entry=0x7fcc6f054e20) at /data/Server/10.11-MDEV-34830/storage/innobase/que/que0que.cc:536
      #27 0x000055ddc8829c4d in que_run_threads_low (thr=thr@entry=0x7fcc6f054e20) at /data/Server/10.11-MDEV-34830/storage/innobase/que/que0que.cc:610
      #28 0x000055ddc8829d14 in que_run_threads (thr=0x7fcc6f054e20) at /data/Server/10.11-MDEV-34830/storage/innobase/que/que0que.cc:630
      #29 0x000055ddc882a44f in que_eval_sql (info=info@entry=0x7fcc6eb97550, sql=sql@entry=0x55ddc9094790 "PROCEDURE DROP_TABLE() IS\niid CHAR;\nDECLARE CURSOR idx IS\nSELECT ID FROM SYS_INDEXES\nWHERE TABLE_ID=:id FOR UPDATE;\nBEGIN\nDELETE FROM SYS_TABLES WHERE ID=:id;\nDELETE FROM SYS_COLUMNS WHERE TABLE_ID=:i"..., trx=trx@entry=0x7fccc5747380)
          at /data/Server/10.11-MDEV-34830/storage/innobase/que/que0que.cc:669
      #30 0x000055ddc8a987f8 in trx_t::drop_table (this=this@entry=0x7fccc5747380, table=...) at /data/Server/10.11-MDEV-34830/storage/innobase/dict/drop.cc:208
      #31 0x000055ddc8ae5b9f in fts_drop_table (trx=trx@entry=0x7fccc5747380, table_name=<optimized out>, table_name@entry=0x7fcc93090ef0 "test/FTS_", '0' <repeats 12 times>, "181e_", '0' <repeats 12 times>, "1e5c_INDEX_4", rename=rename@entry=0x0) at /data/Server/10.11-MDEV-34830/storage/innobase/fts/fts0fts.cc:1403
      #32 0x000055ddc8ae7078 in fts_drop_index_tables (trx=trx@entry=0x7fccc5747380, index=...) at /data/Server/10.11-MDEV-34830/storage/innobase/fts/fts0fts.cc:1725
      #33 0x000055ddc8ae752c in fts_drop_all_index_tables (trx=trx@entry=0x7fccc5747380, fts=<optimized out>) at /data/Server/10.11-MDEV-34830/storage/innobase/fts/fts0fts.cc:1753
      #34 0x000055ddc8ae7659 in fts_drop_tables (trx=trx@entry=0x7fccc5747380, table=...) at /data/Server/10.11-MDEV-34830/storage/innobase/fts/fts0fts.cc:1774
      #35 0x000055ddc8a97f97 in trx_t::drop_table (this=this@entry=0x7fccc5747380, table=...) at /data/Server/10.11-MDEV-34830/storage/innobase/dict/drop.cc:196
      #36 0x000055ddc872030c in commit_try_rebuild (ha_alter_info=ha_alter_info@entry=0x7fcc93092000, ctx=ctx@entry=0x7fcc6c0152e8, altered_table=altered_table@entry=0x7fcc930920c0, old_table=<optimized out>, statistics_exist=<optimized out>, trx=trx@entry=0x7fccc5747380, table_name=<optimized out>) at /data/Server/10.11-MDEV-34830/storage/innobase/handler/handler0alter.cc:10426
      #37 0x000055ddc870d942 in ha_innobase::commit_inplace_alter_table (this=<optimized out>, altered_table=0x7fcc930920c0, ha_alter_info=0x7fcc93092000, commit=0x1) at /data/Server/10.11-MDEV-34830/storage/innobase/handler/handler0alter.cc:11609
      #38 0x000055ddc83754a2 in handler::ha_commit_inplace_alter_table (this=0x7fcc54379590, altered_table=altered_table@entry=0x7fcc930920c0, ha_alter_info=ha_alter_info@entry=0x7fcc93092000, commit=commit@entry=0x1) at /data/Server/10.11-MDEV-34830/sql/handler.cc:5375
      #39 0x000055ddc8139e1d in mysql_inplace_alter_table (thd=thd@entry=0x7fcc6c000d58, table_list=0x7fcc6c013520, table=table@entry=0x7fcc57cbf3f8, altered_table=altered_table@entry=0x7fcc930920c0, ha_alter_info=ha_alter_info@entry=0x7fcc93092000, target_mdl_request=target_mdl_request@entry=0x7fcc93092920, ddl_log_state=0x7fcc93091fc0, trigger_param=0x7fcc930924c0, 
          alter_ctx=0x7fcc930934f0, partial_alter=@0x7fcc93091f5f: 0x0, start_alter_id=@0x7fcc93091f68: 0x0, if_exists=0x0) at /data/Server/10.11-MDEV-34830/sql/sql_table.cc:7977
      #40 0x000055ddc814d2f1 in mysql_alter_table (thd=thd@entry=0x7fcc6c000d58, new_db=new_db@entry=0x7fcc6c0058e0, new_name=<optimized out>, create_info=create_info@entry=0x7fcc93094390, table_list=<optimized out>, table_list@entry=0x7fcc6c013520, recreate_info=recreate_info@entry=0x7fcc930941e0, alter_info=<optimized out>, order_num=<optimized out>, order=<optimized out>, 
          ignore=<optimized out>, if_exists=<optimized out>) at /data/Server/10.11-MDEV-34830/sql/sql_table.cc:11174
      #41 0x000055ddc81d3207 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x7fcc6c000d58) at /data/Server/10.11-MDEV-34830/sql/sql_alter.cc:688
      #42 0x000055ddc80560fa in mysql_execute_command (thd=thd@entry=0x7fcc6c000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=0x0) at /data/Server/10.11-MDEV-34830/sql/sql_parse.cc:6142
      #43 0x000055ddc8057598 in mysql_parse (thd=thd@entry=0x7fcc6c000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7fcc93095370) at /data/Server/10.11-MDEV-34830/sql/sql_parse.cc:8161
      #44 0x000055ddc805997e in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fcc6c000d58, packet=packet@entry=0x7fcc6c00b049 "ALTER TABLE t1 ADD COLUMN extra INT /* E_R Thread9 QNO 1603 CON_ID 19 */ ", packet_length=packet_length@entry=0x49, blocking=blocking@entry=0x1) at /data/Server/10.11-MDEV-34830/sql/sql_parse.cc:1895
      

      I checked the code, and the READ_FIX state should always go hand in hand with a page x-latch. Any io-fix should be released before releasing the page latch.

      I also noticed that this run was with the following parameters:

      • innodb_undo_tablespaces=0
      • innodb_change_buffering=purges

      This could play a role. At the time of the crash, we had innodb_file_per_table=1, but this parameter can be changed while the server is running, or any time between database initialization and the crash.

      I found an earlier bug report MDEV-28274, which also involves the change buffer.

      One more thing: The chances of reproducing this bug should significantly improve by adding the following parameter:

      --debug-dbug=+d,ib_buf_create_intermittent_wait
      

      Attachments

        Issue Links

          Activity

            People

              mleich Matthias Leich
              marko Marko Mäkelä
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.