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

Server crash when trying to alter add Primary Key to InnoDB table

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 10.3.13
    • Fix Version/s: N/A
    • Component/s: OTHER
    • Labels:
      None
    • Environment:
      I have the latest mariadb docker container running on Windows 10 Home edition. MariaDB version: Server version: 10.3.13-MariaDB-1:10.3.13+maria~bionic-log

      Description

      Executing the following statement causes the DB to crash:

      CREATE TABLE `atest` (
        `id` int NOT NULL,
        `name` varchar(20) NOT NULL
      ) ENGINE=InnoDB;
       
      ALTER TABLE `atest` ADD PRIMARY KEY (`id`);
      

      Here's the log I'm getting:

      -- When the container is started
      Database initialized
      MySQL init process in progress...
      2019-02-24 15:51:29 0 [Note] mysqld (mysqld 10.3.13-MariaDB-1:10.3.13+maria~bionic-log) starting as process 109 ...
      2019-02-24 15:51:29 0 [Warning] Setting lower_case_table_names=2 because file system for /var/lib/mysql/ is case insensitive
      2019-02-24 15:51:29 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2019-02-24 15:51:29 0 [Note] InnoDB: Uses event mutexes
      2019-02-24 15:51:29 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2019-02-24 15:51:29 0 [Note] InnoDB: Number of pools: 1
      2019-02-24 15:51:29 0 [Note] InnoDB: Using SSE2 crc32 instructions
      2019-02-24 15:51:29 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
      2019-02-24 15:51:29 0 [Note] InnoDB: Completed initialization of buffer pool
      2019-02-24 15:51:29 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2019-02-24 15:51:30 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
      2019-02-24 15:51:30 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      2019-02-24 15:51:30 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      MySQL init process in progress...
      2019-02-24 15:51:30 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      2019-02-24 15:51:30 0 [Note] InnoDB: Waiting for purge to start
      2019-02-24 15:51:31 0 [Note] InnoDB: 10.3.13 started; log sequence number 1630824; transaction id 21
      2019-02-24 15:51:31 0 [Note] Plugin 'FEEDBACK' is disabled.
      2019-02-24 15:51:31 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
      2019-02-24 15:51:31 0 [Note] InnoDB: Buffer pool(s) load completed at 190224 15:51:31
      2019-02-24 15:51:31 0 [Warning] 'user' entry 'root@865e711deccc' ignored in --skip-name-resolve mode.
      2019-02-24 15:51:31 0 [Warning] 'user' entry '@865e711deccc' ignored in --skip-name-resolve mode.
      2019-02-24 15:51:31 0 [Warning] 'proxies_priv' entry '@% root@865e711deccc' ignored in --skip-name-resolve mode.
      2019-02-24 15:51:31 0 [Note] Reading of all Master_info entries succeded
      2019-02-24 15:51:31 0 [Note] Added new Master_info '' to hash table
      2019-02-24 15:51:31 0 [Note] mysqld: ready for connections.
      Version: '10.3.13-MariaDB-1:10.3.13+maria~bionic-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  mariadb.org binary distribution
      Warning: Unable to load '/usr/share/zoneinfo/leap-seconds.list' as time zone. Skipping it.
      2019-02-24 15:52:10 11 [Warning] 'proxies_priv' entry '@% root@865e711deccc' ignored in --skip-name-resolve mode.
       
      2019-02-24 15:52:10 0 [Note] mysqld (initiated by: unknown): Normal shutdown
      2019-02-24 15:52:10 0 [Note] InnoDB: FTS optimize thread exiting.
      2019-02-24 15:52:10 0 [Note] Event Scheduler: Purging the queue. 0 events
      2019-02-24 15:52:10 0 [Note] InnoDB: Starting shutdown...
      2019-02-24 15:52:10 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
      2019-02-24 15:52:11 0 [Note] InnoDB: Buffer pool(s) dump completed at 190224 15:52:11
      2019-02-24 15:52:11 0 [Note] InnoDB: Shutdown completed; log sequence number 1630833; transaction id 24
      2019-02-24 15:52:11 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
      2019-02-24 15:52:11 0 [Note] mysqld: Shutdown complete
       
       
      MySQL init process done. Ready for start up.
       
      2019-02-24 15:52:11 0 [Note] mysqld (mysqld 10.3.13-MariaDB-1:10.3.13+maria~bionic-log) starting as process 1 ...
      2019-02-24 15:52:11 0 [Warning] Setting lower_case_table_names=2 because file system for /var/lib/mysql/ is case insensitive
      2019-02-24 15:52:11 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2019-02-24 15:52:11 0 [Note] InnoDB: Uses event mutexes
      2019-02-24 15:52:11 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2019-02-24 15:52:11 0 [Note] InnoDB: Number of pools: 1
      2019-02-24 15:52:11 0 [Note] InnoDB: Using SSE2 crc32 instructions
      2019-02-24 15:52:11 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
      2019-02-24 15:52:11 0 [Note] InnoDB: Completed initialization of buffer pool
      2019-02-24 15:52:11 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2019-02-24 15:52:11 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
      2019-02-24 15:52:11 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      2019-02-24 15:52:11 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      2019-02-24 15:52:12 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      2019-02-24 15:52:12 0 [Note] InnoDB: Waiting for purge to start
      2019-02-24 15:52:12 0 [Note] InnoDB: 10.3.13 started; log sequence number 1630833; transaction id 21
      2019-02-24 15:52:12 0 [Note] Plugin 'FEEDBACK' is disabled.
      2019-02-24 15:52:12 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
      2019-02-24 15:52:12 0 [Note] InnoDB: Buffer pool(s) load completed at 190224 15:52:12
      2019-02-24 15:52:12 0 [Note] Server socket created on IP: '::'.
      2019-02-24 15:52:13 0 [Warning] 'proxies_priv' entry '@% root@865e711deccc' ignored in --skip-name-resolve mode.
      2019-02-24 15:52:13 0 [Note] Reading of all Master_info entries succeded
      2019-02-24 15:52:13 0 [Note] Added new Master_info '' to hash table
      2019-02-24 15:52:13 0 [Note] mysqld: ready for connections.
      Version: '10.3.13-MariaDB-1:10.3.13+maria~bionic-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
      2019-02-24 15:52:56 9 [ERROR] InnoDB: Operating system error number 26 in a file operation.
      2019-02-24 15:52:56 9 [ERROR] InnoDB: Error number 26 means 'Text file busy'
      2019-02-24 15:52:56 9 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
      2019-02-24 15:52:56 9 [ERROR] InnoDB: Cannot rename file './appziodb/atest.ibd' to './appziodb/#sql-ib21.ibd'
      2019-02-24 15:52:56 0x7fa05cc58700  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.3.13/storage/innobase/handler/handler0alter.cc line 8817
      InnoDB: Failing assertion: error == DB_SUCCESS
      InnoDB: We intentionally generate a memory trap.
      InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
      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: https://mariadb.com/kb/en/library/innodb-recovery-modes/
      InnoDB: about forcing recovery.
      190224 15:52:56 [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.3.13-MariaDB-1:10.3.13+maria~bionic-log
      key_buffer_size=134217728
      read_buffer_size=2097152
      max_used_connections=1
      max_threads=102
      thread_count=8
      It is possible that mysqld could use up to
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 760012 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x7fa02400a498
      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 = 0x7fa05cc57dd8 thread_stack 0x49000
      mysqld(my_print_stacktrace+0x2e)[0x5560d5ade47e]
      mysqld(handle_fatal_signal+0x5a5)[0x5560d557e295]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7fa07888a890]
      /lib/x86_64-linux-gnu/libc.so.6(gsignal+0xc7)[0x7fa077d9ee97]
      /lib/x86_64-linux-gnu/libc.so.6(abort+0x141)[0x7fa077da0801]
      mysqld(+0x497cfc)[0x5560d52cecfc]
      mysqld(+0x8e6df7)[0x5560d571ddf7]
      mysqld(+0x48eac7)[0x5560d52c5ac7]
      mysqld(_Z17mysql_alter_tableP3THDPK25st_mysql_const_lex_stringS3_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderb+0x2ee0)[0x5560d5430ce0]
      mysqld(_ZN19Sql_cmd_alter_table7executeEP3THD+0x3cf)[0x5560d5480b4f]
      mysqld(_Z21mysql_execute_commandP3THD+0x1226)[0x5560d53a31e6]
      mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x20a)[0x5560d53aaa4a]
      mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1cc7)[0x5560d53ad447]
      mysqld(_Z10do_commandP3THD+0x178)[0x5560d53ae1e8]
      mysqld(_Z24do_handle_one_connectionP7CONNECT+0x212)[0x5560d547dd92]
      mysqld(handle_one_connection+0x3d)[0x5560d547df6d]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x76db)[0x7fa07887f6db]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fa077e8188f]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7fa02401b160): ALTER TABLE `atest` ADD PRIMARY KEY (`id`)
      Connection ID (thread ID): 9
      Status: NOT_KILLED
       
      Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on
      


      -- HERE The container restarts and then I'm getting this log output and the container restarts again

      2019-02-24 15:57:19 0 [Note] mysqld (mysqld 10.3.13-MariaDB-1:10.3.13+maria~bionic-log) starting as process 1 ...
      2019-02-24 15:57:20 0 [Warning] Setting lower_case_table_names=2 because file system for /var/lib/mysql/ is case insensitive
      2019-02-24 15:57:20 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2019-02-24 15:57:20 0 [Note] InnoDB: Uses event mutexes
      2019-02-24 15:57:20 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2019-02-24 15:57:20 0 [Note] InnoDB: Number of pools: 1
      2019-02-24 15:57:20 0 [Note] InnoDB: Using SSE2 crc32 instructions
      2019-02-24 15:57:20 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
      2019-02-24 15:57:20 0 [Note] InnoDB: Completed initialization of buffer pool
      2019-02-24 15:57:20 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2019-02-24 15:57:20 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1635517
      2019-02-24 15:57:20 0 [Note] InnoDB: Ignoring data file './appziodb/atest.ibd' with space ID 6. Another data file called ./appziodb/#sql-1_9.ibd exists with the same space ID.
      2019-02-24 15:57:20 0 [Note] InnoDB: Ignoring data file './appziodb/atest.ibd' with space ID 5. Another data file called ./appziodb/#sql-ib21.ibd exists with the same space ID.
      2019-02-24 15:57:20 0 [Note] InnoDB: Ignoring data file './appziodb/atest.ibd' with space ID 6. Another data file called ./appziodb/#sql-1_9.ibd exists with the same space ID.
      2019-02-24 15:57:20 0 [ERROR] InnoDB: Operating system error number 26 in a file operation.
      2019-02-24 15:57:20 0 [ERROR] InnoDB: Error number 26 means 'Text file busy'
      2019-02-24 15:57:20 0 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
      2019-02-24 15:57:20 0 [ERROR] InnoDB: Cannot rename file './appziodb/#sql-1_9.ibd' to './appziodb/atest.ibd'
      2019-02-24 15:57:20 0x7fb1da2ca7c0  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.3.13/storage/innobase/fil/fil0fil.cc line 2245
      InnoDB: We intentionally generate a memory trap.
      InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
      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: https://mariadb.com/kb/en/library/innodb-recovery-modes/
      InnoDB: about forcing recovery.
      190224 15:57:20 [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.3.13-MariaDB-1:10.3.13+maria~bionic-log
      key_buffer_size=134217728
      read_buffer_size=2097152
      max_used_connections=0
      max_threads=102
      thread_count=0
      It is possible that mysqld could use up to
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 760012 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x0
      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 = 0x0 thread_stack 0x49000
      mysqld(my_print_stacktrace+0x2e)[0x561566e4d47e]
      mysqld(handle_fatal_signal+0x5a5)[0x5615668ed295]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7fb1d864c890]
      /lib/x86_64-linux-gnu/libc.so.6(gsignal+0xc7)[0x7fb1d7b60e97]
      /lib/x86_64-linux-gnu/libc.so.6(abort+0x141)[0x7fb1d7b62801]
      mysqld(+0x497cfc)[0x56156663dcfc]
      mysqld(+0xac3f1e)[0x561566c69f1e]
      mysqld(+0x92370b)[0x561566ac970b]
      mysqld(+0x92654f)[0x561566acc54f]
      mysqld(+0x926a07)[0x561566acca07]
      mysqld(+0x92704b)[0x561566acd04b]
      mysqld(+0x927443)[0x561566acd443]
      mysqld(+0x927a01)[0x561566acda01]
      mysqld(+0x9d3cd1)[0x561566b79cd1]
      mysqld(+0x8c6741)[0x561566a6c741]
      mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x62)[0x5615668ef8f2]
      mysqld(+0x57ffa9)[0x561566725fa9]
      mysqld(_Z11plugin_initPiPPci+0x85a)[0x56156672710a]
      mysqld(+0x4b6df1)[0x56156665cdf1]
      mysqld(_Z11mysqld_mainiPPc+0x53a)[0x56156666302a]
      /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xe7)[0x7fb1d7b43b97]
      mysqld(_start+0x2a)[0x561566655f1a]
      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.
      Fatal signal 11 while backtracing
      

      Attached is also the my.cnf. Because of issues with O_DIRECT and VirtualBox I had to use this configuration in order to run on windows:
      innodb_use_native_aio=0
      innodb_flush_method=O_DSYNC
      log_bin=ON

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              Unassigned
              Reporter:
              stefolog Stefan Vartolomeev
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: