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

IMPORT TABLESPACE must not go beyond FSP_FREE_LIMIT

Details

    • 10.1.29

    Description

      Test imported from MariaDB 10.2.
      1) innodb_zip.wl5522_debug_zip '4k,innodb_plugin' fails in 10.0, assertion: block->page.space == page_get_space_id(page_align(ptr)) in file buf0buf.cc line 2394

      2) innodb_zip.wl5522_debug_zip '16k,innodb_plugin' --line 516: query 'ALTER TABLE test_wl5522.t1 IMPORT TABLESPACE' succeeded - should have failed with errno 1815...

      worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
      innodb_zip.wl5522_debug_zip '4k,innodb_plugin' [ fail ]
              Test ended at 2017-10-26 12:53:23
       
      CURRENT_TEST: innodb_zip.wl5522_debug_zip
      mysqltest: At line 424: query 'ALTER TABLE test_wl5522.t1 IMPORT TABLESPACE' failed: 2013: Lost connection to MySQL server during query
       
      The result from queries just before the failure was:
      < snip >
      FROM information_schema.innodb_metrics
      WHERE name = 'ibuf_merges_inserts' AND count > 0;
      name
      SET GLOBAL innodb_disable_background_merge=OFF;
      COMMIT;
      DROP TABLE test_wl5522.t1;
      CREATE TABLE test_wl5522.t1 (
      c1 BIGINT NOT NULL AUTO_INCREMENT PRIMARY KEY,
      c2 BIGINT,
      c3 VARCHAR(2048),
      c4 VARCHAR(2048),
      INDEX idx1(c2),
      INDEX idx2(c3(512)),
      INDEX idx3(c4(512))) Engine=InnoDB
      ROW_FORMAT=COMPRESSED;
      SELECT c1, c2 FROM test_wl5522.t1;
      c1	c2
      ALTER TABLE test_wl5522.t1 DISCARD TABLESPACE;
      restore: t1 .ibd and .cfg files
      ALTER TABLE test_wl5522.t1 IMPORT TABLESPACE;
      

      2017-10-26 12:57:52 7fca76524700  InnoDB: Assertion failure in thread 140507545224960 in file buf0buf.cc line 2394
      InnoDB: Failing assertion: block->page.space == page_get_space_id(page_align(ptr))
      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/5.6/en/forcing-innodb-recovery.html
      InnoDB: about forcing recovery.
      171026 12:57:52 [ERROR] mysqld got signal 6 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.
       
      To report this bug, see https://mariadb.com/kb/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed, 
      something is definitely wrong and this may fail.
       
      Server version: 10.0.33-MariaDB-debug
      key_buffer_size=1048576
      read_buffer_size=131072
      max_used_connections=2
      max_threads=153
      thread_count=1
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62856 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x7fca687a3070
      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 = 0x7fca76523e28 thread_stack 0x48000
      mysys/stacktrace.c:267(my_print_stacktrace)[0xea597d]
      sql/signal_handler.cc:161(handle_fatal_signal)[0x864df0]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7fca75672390]
      /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x38)[0x7fca74390428]
      /lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7fca7439202a]
      /home/alice/aliska/10.0/mysql-test/var/plugins/ha_innodb.so(+0x9b37e)[0x7fca6ca7637e]
      /home/alice/aliska/10.0/mysql-test/var/plugins/ha_innodb.so(+0x9b43a)[0x7fca6ca7643a]
      /home/alice/aliska/10.0/mysql-test/var/plugins/ha_innodb.so(+0x1d651d)[0x7fca6cbb151d]
      /home/alice/aliska/10.0/mysql-test/var/plugins/ha_innodb.so(+0x19d33d)[0x7fca6cb7833d]
      /home/alice/aliska/10.0/mysql-test/var/plugins/ha_innodb.so(+0x1a63f4)[0x7fca6cb813f4]
      /home/alice/aliska/10.0/mysql-test/var/plugins/ha_innodb.so(+0x23186c)[0x7fca6cc0c86c]
      /home/alice/aliska/10.0/mysql-test/var/plugins/ha_innodb.so(+0x160c89)[0x7fca6cb3bc89]
      sql/handler.cc:4196(handler::ha_discard_or_import_tablespace(char))[0x86f25c]
      sql/sql_table.cc:5640(mysql_discard_or_import_tablespace(THD*, TABLE_LIST*, bool))[0x716653]
      sql/sql_alter.cc:346(Sql_cmd_discard_import_tablespace::execute(THD*))[0x78f6df]
      sql/sql_parse.cc:5123(mysql_execute_command(THD*))[0x66112a]
      sql/sql_parse.cc:6578(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x664ade]
      sql/sql_parse.cc:1307(dispatch_command(enum_server_command, THD*, char*, unsigned int))[0x656be7]
      sql/sql_parse.cc:999(do_command(THD*))[0x655e74]
      sql/sql_connect.cc:1377(do_handle_one_connection(THD*))[0x78a76c]
      sql/sql_connect.cc:1293(handle_one_connection)[0x78a4ba]
      perfschema/pfs.cc:1862(pfs_spawn_thread)[0xa58902]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7fca756686ba]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fca744623dd]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7fca5fcf8088): ALTER TABLE test_wl5522.t1 IMPORT TABLESPACE
      Connection ID (thread ID): 2
      Status: NOT_KILLED
      

      Thread 1 (Thread 0x7fca76524700 (LWP 31457)):
      #0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:62
      #1  0x0000000000ea5a83 in my_write_core (sig=6) at /home/alice/aliska/10.0/mysys/stacktrace.c:478
      #2  0x0000000000865171 in handle_fatal_signal (sig=6) at /home/alice/aliska/10.0/sql/signal_handler.cc:285
      #3  <signal handler called>
      #4  0x00007fca74390428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
      #5  0x00007fca7439202a in __GI_abort () at abort.c:89
      #6  0x00007fca6ca7637e in buf_block_align_instance (buf_pool=0x7fca73827978, ptr=0x7fca6c6c2000 "") at /home/alice/aliska/10.0/storage/innobase/buf/buf0buf.cc:2393
      #7  0x00007fca6ca7643a in buf_block_align (ptr=0x7fca6c6c2000 "") at /home/alice/aliska/10.0/storage/innobase/buf/buf0buf.cc:2425
      #8  0x00007fca6cbb151d in mtr_memo_contains_page (mtr=0x7fca765213a0, ptr=0x7fca6c6c2000 "", type=2) at /home/alice/aliska/10.0/storage/innobase/mtr/mtr0mtr.cc:420
      #9  0x00007fca6cb7833d in ibuf_bitmap_page_get_bits_low (page=0x7fca6c6c2000 "", page_no=2050, zip_size=2048, latch_type=2, mtr=0x7fca765213a0, bit=3) at /home/alice/aliska/10.0/storage/innobase/ibuf/ibuf0ibuf.cc:728
      #10 0x00007fca6cb813f4 in ibuf_check_bitmap_on_import (trx=0x7fca5fd48278, space_id=10) at /home/alice/aliska/10.0/storage/innobase/ibuf/ibuf0ibuf.cc:5134
      #11 0x00007fca6cc0c86c in row_import_for_mysql (table=0x7fca5fd3ed78, prebuilt=0x7fca5fe89078) at /home/alice/aliska/10.0/storage/innobase/row/row0import.cc:3658
      #12 0x00007fca6cb3bc89 in ha_innodb::discard_or_import_tablespace (this=0x7fca5fc76888, discard=0 '\000') at /home/alice/aliska/10.0/storage/innobase/handler/ha_innodb.cc:10586
      #13 0x000000000086f25c in handler::ha_discard_or_import_tablespace (this=0x7fca5fc76888, discard=0 '\000') at /home/alice/aliska/10.0/sql/handler.cc:4195
      #14 0x0000000000716653 in mysql_discard_or_import_tablespace (thd=0x7fca687a3070, table_list=0x7fca5fcf81a0, discard=false) at /home/alice/aliska/10.0/sql/sql_table.cc:5640
      #15 0x000000000078f6df in Sql_cmd_discard_import_tablespace::execute (this=0x7fca5fcf8780, thd=0x7fca687a3070) at /home/alice/aliska/10.0/sql/sql_alter.cc:345
      #16 0x000000000066112a in mysql_execute_command (thd=0x7fca687a3070) at /home/alice/aliska/10.0/sql/sql_parse.cc:5123
      #17 0x0000000000664ade in mysql_parse (thd=0x7fca687a3070, rawbuf=0x7fca5fcf8088 "ALTER TABLE test_wl5522.t1 IMPORT TABLESPACE", length=44, parser_state=0x7fca76523670) at /home/alice/aliska/10.0/sql/sql_parse.cc:6578
      #18 0x0000000000656be7 in dispatch_command (command=COM_QUERY, thd=0x7fca687a3070, packet=0x7fca6e1f3071 "ALTER TABLE test_wl5522.t1 IMPORT TABLESPACE", packet_length=44) at /home/alice/aliska/10.0/sql/sql_parse.cc:1305
      #19 0x0000000000655e74 in do_command (thd=0x7fca687a3070) at /home/alice/aliska/10.0/sql/sql_parse.cc:999
      #20 0x000000000078a76c in do_handle_one_connection (thd_arg=0x7fca687a3070) at /home/alice/aliska/10.0/sql/sql_connect.cc:1377
      #21 0x000000000078a4ba in handle_one_connection (arg=0x7fca687a3070) at /home/alice/aliska/10.0/sql/sql_connect.cc:1292
      #22 0x0000000000a58902 in pfs_spawn_thread (arg=0x7fca686c33f0) at /home/alice/aliska/10.0/storage/perfschema/pfs.cc:1860
      #23 0x00007fca756686ba in start_thread (arg=0x7fca76524700) at pthread_create.c:333
      #24 0x00007fca744623dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
      

      Attachments

        Issue Links

          Activity

            I can repeat this on 10.0 as follows:

            cp {../10.2/,}mysql-test/suite/innodb_zip/t/wl5522_debug_zip.test
            ./mtr --mysqld=--innodb-file-format=1 --mem innodb_zip.wl5522_debug_zip,4k
            

            The problem here is that the 2nd change buffer bitmap page (tablespace id 10, page number 2049) is filled with all zeroes.
            At the time of the crash, there is no page 2048 for this tablespace, but I can look at the file mysql-test/var/log/innodb_zip.wl5522_debug_zip-4k,xtradb/tmp/t1.ibd (which uses the original tablespace ID 9) to see what is going on.
            The file size is 4096*2048 bytes. One might expect pages 2048 and 2049 to contain valid bitmaps for the last 2048 pages. But, if the page header says that less than 2048 pages are actually used, then the bitmap pages are not required to exist.

            It turns out that the last used page in the file starts at offset 0x123000 (page number 582).
            One problem would seem to be that the file is unnecessarily large (almost 4 times the payload size).
            Another problem would seem to be that IMPORT insists that the bitmap pages be initialized.
            The first page of the t1.ibd file starts as follows:

            000000 1e c3 fd 49 00 00 00 00 00 00 00 00 00 00 00 00
            000010 00 00 00 00 00 47 77 99 00 08 00 00 00 00 00 00
            000020 00 00 00 00 00 09 00 00 00 09 00 00 00 00 00 00
            000030 10 00 00 00 04 00 00 00 00 e5 00 00 00 f0 00 00
            000040 00 01 00 00 00 00 01 a6 00 00 00 00 01 a6 00 00
            000050 00 01 00 00 00 00 00 9e 00 00 00 00 00 9e 00 00
            

            At 0x26 we have the FSP_SPACE_ID which is equal to the FIL_PAGE_SPACE_ID right before it (9).
            At 0x2e we have the FSP_SIZE: 0x1000 (4096) pages.
            At 0x32 we have the FSP_FREE_LIMIT: 0x400 (2048). So, clearly the bitmap pages 2048 or 2049 should not be expected to be valid.

            This is a bug in ibuf_check_bitmap_on_import(): it should not iterate all FSP_SIZE pages of the tablespace, but only the pages up to the FSP_FREE_LIMIT.

            marko Marko Mäkelä added a comment - I can repeat this on 10.0 as follows: cp {../10.2/,}mysql-test/suite/innodb_zip/t/wl5522_debug_zip.test ./mtr --mysqld=--innodb-file-format=1 --mem innodb_zip.wl5522_debug_zip,4k The problem here is that the 2nd change buffer bitmap page (tablespace id 10, page number 2049) is filled with all zeroes. At the time of the crash, there is no page 2048 for this tablespace, but I can look at the file mysql-test/var/log/innodb_zip.wl5522_debug_zip-4k,xtradb/tmp/t1.ibd (which uses the original tablespace ID 9) to see what is going on. The file size is 4096*2048 bytes. One might expect pages 2048 and 2049 to contain valid bitmaps for the last 2048 pages. But, if the page header says that less than 2048 pages are actually used, then the bitmap pages are not required to exist. It turns out that the last used page in the file starts at offset 0x123000 (page number 582). One problem would seem to be that the file is unnecessarily large (almost 4 times the payload size). Another problem would seem to be that IMPORT insists that the bitmap pages be initialized. The first page of the t1.ibd file starts as follows: 000000 1e c3 fd 49 00 00 00 00 00 00 00 00 00 00 00 00 000010 00 00 00 00 00 47 77 99 00 08 00 00 00 00 00 00 000020 00 00 00 00 00 09 00 00 00 09 00 00 00 00 00 00 000030 10 00 00 00 04 00 00 00 00 e5 00 00 00 f0 00 00 000040 00 01 00 00 00 00 01 a6 00 00 00 00 01 a6 00 00 000050 00 01 00 00 00 00 00 9e 00 00 00 00 00 9e 00 00 At 0x26 we have the FSP_SPACE_ID which is equal to the FIL_PAGE_SPACE_ID right before it (9). At 0x2e we have the FSP_SIZE: 0x1000 (4096) pages. At 0x32 we have the FSP_FREE_LIMIT: 0x400 (2048). So, clearly the bitmap pages 2048 or 2049 should not be expected to be valid. This is a bug in ibuf_check_bitmap_on_import(): it should not iterate all FSP_SIZE pages of the tablespace, but only the pages up to the FSP_FREE_LIMIT.

            Actually the test exists in 10.0 already, with a different name: innodb.innodb-wl5522-debug-zip.
            But, that test only allows innodb_page_size=16k.

            I think that the correct solution is to replace the 10.0 test with the test from 10.2, with suitable adjustments.

            marko Marko Mäkelä added a comment - Actually the test exists in 10.0 already, with a different name: innodb.innodb-wl5522-debug-zip. But, that test only allows innodb_page_size=16k. I think that the correct solution is to replace the 10.0 test with the test from 10.2, with suitable adjustments.

            I pushed to 10.0 and merged to 10.1 (with some conflicts resolved) so far.
            The merge to 10.2 may require some effort.

            marko Marko Mäkelä added a comment - I pushed to 10.0 and merged to 10.1 (with some conflicts resolved) so far. The merge to 10.2 may require some effort.

            People

              marko Marko Mäkelä
              alice Alice Sherepa
              Votes:
              0 Vote for this issue
              Watchers:
              3 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.