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

InnoDB: Failing assertion: fsize != os_offset_t(-1) on CREATE TABLE with many partitions / ENOMEM (out of kernel memory) from fstat handling

    XMLWordPrintable

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Incomplete
    • 10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5, 10.6, 10.7(EOL), 11.0(EOL), 11.2(EOL)
    • N/A
    • Storage Engine - InnoDB
    • None

    Description

      The attached (3 line) testcase ( MDEV-26381_1.sql ) is not finalized. Whilst I am confident that the said testcase can produce the assertion as-is (it was reduced to this based on seeing the assert or not), reproducing the crash itself is not straightforward. It may be highly sporadic, or more likely dependent on some system condition (like running out of file descriptors, some OS shortcoming, or similar). As discussed elsewhere, the issue is likely not confined to partitioning but is rather related to the accessing of many .ibd files whilst running into a [bad] file descriptor issue,. There is a core file and Marko will analyze that one. [DONE]

      Possibly related: MDEV-20648 , MDEV-26293 (likely)

      mysqld options from original run. Not all necessary.

      --max_allowed_packet=33554432 --maximum-bulk_insert_buffer_size=1M --maximum-join_buffer_size=1M --maximum-max_heap_table_size=1M --maximum-max_join_size=1M --maximum-myisam_max_sort_file_size=1M --maximum-myisam_mmap_size=1M --maximum-myisam_sort_buffer_size=1M --maximum-optimizer_trace_max_mem_size=1M --maximum-preload_buffer_size=1M --maximum-query_alloc_block_size=1M --maximum-query_prealloc_size=1M --maximum-range_alloc_block_size=1M --maximum-read_buffer_size=1M --maximum-read_rnd_buffer_size=1M --maximum-sort_buffer_size=1M --maximum-tmp_table_size=1M --maximum-transaction_alloc_block_size=1M --maximum-transaction_prealloc_size=1M --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --log_bin --innodb_file_per_table=1 --innodb_flush_method=O_DIRECT  --table-cache=2 --symbolic-links=0 --innodb-log-checksums=0

      10.6.4 42b9daaea7ece6155558f7c3bf638e8e175a7ff7 (Optimized)

      		 
      InnoDB: Failing assertion: fsize != os_offset_t(-1)

      10.6.4 42b9daaea7ece6155558f7c3bf638e8e175a7ff7 (Optimized)

      		 
      Core was generated by `/test/MD260721-mariadb-10.6.4-linux-x86_64-opt/bin/mysqld --no-defaults --max_a'.
      		 
      Program terminated with signal SIGABRT, Aborted.
      		 
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      		 
      [Current thread is 1 (Thread 0x14e10c449700 (LWP 3154497))]
      		 
      (gdb) bt
      		 
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      		 
      #1  0x000014e10d840859 in __GI_abort () at abort.c:79
      		 
      #2  0x000055b95dd66b11 in ut_dbg_assertion_failed (expr=expr@entry=0x55b95e9746b6 "fsize != os_offset_t(-1)", file=file@entry=0x55b95e973e70 "/test/10.6_opt/storage/innobase/fil/fil0fil.cc", line=line@entry=591) at /test/10.6_opt/storage/innobase/ut/ut0dbg.cc:60
      		 
      #3  0x000055b95dd77806 in fil_space_extend_must_retry (space=space@entry=0x14e070cdb488, node=0x14e070cdb5e8, size=size@entry=6, success=success@entry=0x14e10c444bdf) at /test/10.6_opt/storage/innobase/fil/fil0fil.cc:591
      		 
      #4  0x000055b95dd77b45 in fil_space_extend (space=space@entry=0x14e070cdb488, size=6) at /test/10.6_opt/storage/innobase/fil/fil0fil.cc:705
      		 
      #5  0x000055b95dd7ab4d in fsp_try_extend_data_file_with_pages (space=0x14e070cdb488, page_no=<optimized out>, header=0x14e0ec018480, mtr=0x14e10c445000) at /test/10.6_opt/storage/innobase/fsp/fsp0fsp.cc:625
      		 
      #6  0x000055b95e58544d in fseg_create (space=space@entry=0x14e070cdb488, byte_offset=byte_offset@entry=74, mtr=mtr@entry=0x14e10c445000, has_done_reservation=has_done_reservation@entry=false, block=block@entry=0x14e0ec0bcb80) at /test/10.6_opt/storage/innobase/fsp/fsp0fsp.cc:1698
      		 
      #7  0x000055b95e4f7474 in btr_create (type=1, space=0x14e070cdb488, index_id=4850, index=index@entry=0x14e070a11db0, mtr=mtr@entry=0x14e10c445000) at /test/10.6_opt/storage/innobase/btr/btr0btr.cc:1031
      		 
      #8  0x000055b95e5477ad in dict_create_index_tree_step (node=0x14e07813a200) at /test/10.6_opt/storage/innobase/dict/dict0crea.cc:768
      		 
      #9  0x000055b95e548177 in dict_create_index_step (thr=thr@entry=0x14e07105f5c0) at /test/10.6_opt/storage/innobase/dict/dict0crea.cc:1249
      		 
      #10 0x000055b95e467488 in que_thr_step (thr=0x14e07105f5c0) at /test/10.6_opt/storage/innobase/que/que0que.cc:663
      		 
      #11 que_run_threads_low (thr=<optimized out>) at /test/10.6_opt/storage/innobase/que/que0que.cc:709
      		 
      #12 que_run_threads (thr=thr@entry=0x14e07105f5c0) at /test/10.6_opt/storage/innobase/que/que0que.cc:729
      		 
      #13 0x000055b95e494d10 in row_create_index_for_mysql (index=<optimized out>, trx=0x14e10c750330, field_lengths=field_lengths@entry=0x0, mode=FIL_ENCRYPTION_DEFAULT, key_id=<optimized out>) at /test/10.6_opt/storage/innobase/row/row0mysql.cc:2394
      		 
      #14 0x000055b95e3eb653 in create_table_info_t::create_table (this=0x14e10c445920, create_fk=<optimized out>) at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:12603
      		 
      #15 0x000055b95e3ef791 in ha_innobase::create (this=<optimized out>, name=0x14e10c4460e0 "./test/t2#P#p4560", form=<optimized out>, create_info=<optimized out>, file_per_table=<optimized out>, trx=0x14e10c750330) at /test/10.6_opt/storage/innobase/handler/ha_innodb.cc:13135
      		 
      #16 0x000055b95e0d49c4 in handler::ha_create (this=<optimized out>, name=name@entry=0x14e10c4460e0 "./test/t2#P#p4560", form=form@entry=0x14e10c446420, info_arg=info_arg@entry=0x14e10c447c70) at /test/10.6_opt/sql/handler.cc:5405
      		 
      #17 0x000055b95e32ab40 in ha_partition::create (this=0x14e079158bd0, name=0x14e10c447780 "./test/t2", table_arg=0x14e10c446420, create_info=0x14e10c447c70) at /test/10.6_opt/sql/ha_partition.cc:786
      		 
      #18 0x000055b95e0d49c4 in handler::ha_create (this=<optimized out>, name=<optimized out>, form=0x14e10c446420, info_arg=0x14e10c447c70) at /test/10.6_opt/sql/handler.cc:5405
      		 
      #19 0x000055b95e0d52ca in ha_create_table (thd=thd@entry=0x14e078000c58, path=<optimized out>, db=0x14e078011030 "test", table_name=0x14e078010918 "t2", create_info=create_info@entry=0x14e10c447c70, frm=frm@entry=0x14e10c447770, skip_frm_file=false) at /test/10.6_opt/sql/handler.cc:5870
      		 
      #20 0x000055b95df3f655 in create_table_impl (thd=thd@entry=0x14e078000c58, ddl_log_state_create=ddl_log_state_create@entry=0x14e10c447a20, ddl_log_state_rm=<optimized out>, orig_db=@0x14e078010968: {str = 0x14e078011030 "test", length = 4}, orig_table_name=@0x14e078010978: {str = 0x14e078010918 "t2", length = 2}, db=@0x14e078010968: {str = 0x14e078011030 "test", length = 4}, table_name=@0x14e078010978: {str = 0x14e078010918 "t2", length = 2}, path=@0x14e10c447760: {str = 0x14e10c447780 "./test/t2", length = 9}, options={m_options = DDL_options_st::OPT_NONE}, create_info=0x14e10c447c70, alter_info=0x14e10c447b80, create_table_mode=0, is_trans=0x14e10c447a1f, key_info=0x14e10c447758, key_count=0x14e10c447754, frm=0x14e10c447770) at /test/10.6_opt/sql/sql_table.cc:4447
      		 
      #21 0x000055b95df3ffd8 in mysql_create_table_no_lock (thd=thd@entry=0x14e078000c58, ddl_log_state_create=ddl_log_state_create@entry=0x14e10c447a20, ddl_log_state_rm=ddl_log_state_rm@entry=0x14e10c447a40, db=db@entry=0x14e078010968, table_name=table_name@entry=0x14e078010978, create_info=create_info@entry=0x14e10c447c70, alter_info=0x14e10c447b80, is_trans=0x14e10c447a1f, create_table_mode=0, table_list=0x14e078010950) at /test/10.6_opt/sql/sql_table.cc:4546
      		 
      #22 0x000055b95df403c4 in mysql_create_table (thd=thd@entry=0x14e078000c58, create_table=create_table@entry=0x14e078010950, create_info=create_info@entry=0x14e10c447c70, alter_info=alter_info@entry=0x14e10c447b80) at /test/10.6_opt/sql/sql_table.cc:4658
      		 
      #23 0x000055b95df41c59 in Sql_cmd_create_table_like::execute (this=<optimized out>, thd=0x14e078000c58) at /test/10.6_opt/sql/sql_table.cc:11778
      		 
      #24 0x000055b95de9d63e in mysql_execute_command (thd=0x14e078000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:5993
      		 
      #25 0x000055b95de8da46 in mysql_parse (thd=0x14e078000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.6_opt/sql/sql_parse.cc:8026
      		 
      #26 0x000055b95de99945 in dispatch_command (command=COM_QUERY, thd=0x14e078000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.6_opt/sql/sql_class.h:1340
      		 
      #27 0x000055b95de9b867 in do_command (thd=0x14e078000c58, blocking=blocking@entry=true) at /test/10.6_opt/sql/sql_parse.cc:1404
      		 
      #28 0x000055b95dfaa017 in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at /test/10.6_opt/sql/sql_connect.cc:1410
      		 
      #29 0x000055b95dfaa37d in handle_one_connection (arg=arg@entry=0x55b95fbcad18) at /test/10.6_opt/sql/sql_connect.cc:1312
      		 
      #30 0x000055b95e334948 in pfs_spawn_thread (arg=0x55b960067bf8) at /test/10.6_opt/storage/perfschema/pfs.cc:2201
      		 
      #31 0x000014e10dd4f609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      		 
      #32 0x000014e10d93d293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

      10.6.4 42b9daaea7ece6155558f7c3bf638e8e175a7ff7 (Optimized)

      		 
      ...
      		 
      2021-07-29  0:00:17 8 [Note] InnoDB: Cannot close file ./test/t2#P#p2604.ibd because of 0 pending operations and pending fsync
      		 
      2021-07-29  0:00:17 8 [Note] InnoDB: Cannot close file ./test/t2#P#p2605.ibd because of 0 pending operations and pending fsync
      		 
      2021-07-29  0:00:17 8 [Note] InnoDB: Cannot close file ./test/t2#P#p2606.ibd because of 0 pending operations and pending fsync
      		 
      2021-07-29  0:00:17 8 [ERROR] InnoDB: preallocating 98304 bytes for file ./test/t2#P#p4560.ibd failed with error 9
      		 
      2021-07-29 00:00:17 0x14e10c449700  InnoDB: Assertion failure in file /test/10.6_opt/storage/innobase/fil/fil0fil.cc line 591
      		 
      InnoDB: Failing assertion: fsize != os_offset_t(-1)
      		 
      InnoDB: We intentionally generate a memory trap.

      Attachments

        1. MDEV-26381_1.sql
          412 kB
        2. MDEV-26381_2.sql
          548 kB
        3. MDEV-26381_3.sql
          413 kB
        4. MDEV-26381_4.sql
          1.06 MB
        5. MDEV-26381_OTHER_1.sql
          2 kB
        6. MDEV-26381_OTHER_1.threads_partial_unlock.dbg.log
          1.90 MB
        7. MDEV-26381_OTHER_1.threads.dbg.log
          1.90 MB
        8. MDEV-26381_OTHER_2.sql
          2.64 MB
        9. MDEV-26381_OTHER_2.threads.opt.log
          1.10 MB

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-26068 Server crashes when innodb-data-file-size-debug set to 1

          • Major - Major loss of function.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-26293 InnoDB: Failing assertion: space->is_ready_to_close() || space->purpose == FIL_TYPE_TEMPORARY || srv_fast_shutdown == 2 || !srv_was_started

          • Major - Major loss of function.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-34938 Under Windows Subsystem for Linux, InnoDB crashes on ALTER TABLE or OPTIMIZE TABLE

          • Blocker - Blocks development and/or testing work, production could not run.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-25215 Excessive logging "Cannot close file ./test/FTS_xxx.ibd because of n pending operations and pending fsync

          • Major - Major loss of function.
          • Closed
          split to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-26873 Partial server hang when using many threads

          • Major - Major loss of function.
          • Closed

          Activity

            People

              danblack Daniel Black
              Roel Roel Van de Paar
              Votes:
              2 Vote for this issue
              Watchers:
              9 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

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