[MDEV-8386] MARIADB creates very big tmp file > 351Gb. Started happening after Version 10.0.16-15 Created: 2015-06-26  Updated: 2017-04-27  Resolved: 2015-07-21

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Alter Table, Storage Engine - InnoDB
Affects Version/s: 10.0.16
Fix Version/s: 10.0.17

Type: Bug Priority: Major
Reporter: Nirbhay Choubey (Inactive) Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: None

Attachments: File createTable.sql     File sysvars.out    
Issue Links:
Relates
relates to MDEV-8447 alter table loops internally and fill... Closed
relates to MDEV-12609 Allow suppression of InnoDB log messa... Closed

 Description   

ALTER enters into an infinite loop on reserving extents until system runs out of disk mysqld aborts.

#!/bin/bash
 
mysql="mysql -uroot -S /var/run/mysql/mysql.sock "
 
$mysql test < ./createTable.sql
 
#for i in $( seq 22 1 122 ); do
for i in $( seq 22 1 2722 ); do
  echo $i
  $mysql test -e "INSERT INTO \`mdl_course_modules\` VALUES ($i,4,5,5,24,NULL,1141569781,'',0,0,1,0,'',0,'locked',1,1,0,0,0,0,NULL,0,0,0,0,0,0);"
done
 
$mysql test -e "ALTER TABLE test.mdl_course_modules ADD stefantest LONGTEXT CHARACTER SET utf8 COLLATE utf8_general_ci AFTER showdescription;"

sles12-x86-64:/var/lib/mysql/test # ls -ahl
total 9.0G
-rw-rw---- 1 mysql mysql  6.2K Jun  2 12:52 #sql-ba5_b99.frm
-rw-rw---- 1 mysql mysql  9.0G Jun  2 13:08 #sql-ib18-3361842814.ibd
drwx------ 1 mysql root    168 Jun  2 12:52 .
drwx------ 1 mysql root    248 Jun  2 13:08 ..
-rw-rw---- 1 mysql mysql  6.2K Jun  2 12:46 mdl_course_modules.frm
-rw-rw---- 1 mysql mysql 1008K Jun  2 12:52 mdl_course_modules.ibd



 Comments   
Comment by Nirbhay Choubey (Inactive) [ 2015-06-26 ]

The issue, so far, could be reproduced only on SLES12 with --no-defaults.

Comment by Nirbhay Choubey (Inactive) [ 2015-06-26 ]

Innodb keeps filling the temporary table ibd file seemingly in an infinite loop on ALTER INPLACE.
The bug report has a test case, with which I could reproduce the issue only on SLES12 and with
the given rpm packages. With a custom build the issue could not be reproduced.

At the end mysqld aborts with the following stack trace :

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fdf48268700 (LWP 12374)]
0x00007fdf6c2e4187 in raise () from /lib64/libc.so.6
(gdb) bt
#0  0x00007fdf6c2e4187 in raise () from /lib64/libc.so.6
#1  0x00007fdf6c2e5538 in abort () from /lib64/libc.so.6
#2  0x0000000000b1d4bb in sync_thread_add_level (latch=0x1dfd940 <dict_operation_lock>, level=1010, relock=0)
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/sync/sync0sync.cc:1287
#3  0x0000000000b1a315 in rw_lock_add_debug_info (lock=lock@entry=0x1dfd940 <dict_operation_lock>, pass=pass@entry=0, 
    lock_type=lock_type@entry=351, 
    file_name=file_name@entry=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc", line=line@entry=4181) at /usr/src/debug/mariadb-10.0.16/storage/xtradb/sync/sync0rw.cc:985
#4  0x0000000000b1b00a in rw_lock_x_lock_low (line=4181, 
    file_name=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc", pass=0, 
    high_priority=false, lock=0x1dfd940 <dict_operation_lock>)
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/sync/sync0rw.cc:738
#5  rw_lock_x_lock_func (lock=lock@entry=0x1dfd940 <dict_operation_lock>, pass=pass@entry=0, 
    file_name=file_name@entry=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc", line=line@entry=4181, priority_lock=priority_lock@entry=false, high_priority=high_priority@entry=false)
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/sync/sync0rw.cc:796
#6  0x0000000000accb96 in pfs_rw_lock_x_lock_func (lock=<optimized out>, pass=0, line=4181, 
    file_name=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc")
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/include/sync0rw.ic:890
#7  row_mysql_lock_data_dictionary_func (trx=0x7fdf08017688, 
    file=file@entry=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc", 
    line=line@entry=4181) at /usr/src/debug/mariadb-10.0.16/storage/xtradb/row/row0mysql.cc:2184
#8  0x0000000000a06923 in rollback_inplace_alter_table (prebuilt=0x7fdf1003a8e8, table=0x7fdf10031470, 
    ha_alter_info=0x7fdf48264080) at /usr/src/debug/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc:4181
#9  ha_innobase::commit_inplace_alter_table (this=0x7fdf10036d68, altered_table=0x7fdf0800ed50, 
    ha_alter_info=0x7fdf48264080, commit=<optimized out>)
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc:5431
#10 0x00000000006a07da in mysql_inplace_alter_table (target_mdl_request=0x7fdf482641b0, alter_ctx=0x7fdf48264d40, 
    inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, ha_alter_info=0x7fdf48264080, 
    altered_table=0x7fdf0800ed50, table=0x7fdf10031470, table_list=0x7fdf08005408, thd=0x7fdf10031470)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_table.cc:7140
#11 mysql_alter_table (thd=thd@entry=0x2f7aa00, new_db=<optimized out>, new_name=<optimized out>, 
    create_info=create_info@entry=0x7fdf48265920, table_list=table_list@entry=0x7fdf08005408, 
    alter_info=alter_info@entry=0x7fdf48265890, order_num=0, order=0x0, ignore=false)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_table.cc:8815
#12 0x00000000006efdd2 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x2f7aa00)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_alter.cc:312
#13 0x000000000060a12b in mysql_execute_command (thd=thd@entry=0x2f7aa00)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_parse.cc:5079
#14 0x0000000000613107 in mysql_parse (thd=thd@entry=0x2f7aa00, rawbuf=<optimized out>, length=124, 
    parser_state=parser_state@entry=0x7fdf482676b0) at /usr/src/debug/mariadb-10.0.16/sql/sql_parse.cc:6513
#15 0x0000000000614d33 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x2f7aa00, 
    packet=packet@entry=0x2f814b1 "ALTER TABLE test.mdl_course_modules ADD stefantest LONGTEXT CHARACTER SET utf8 COLLATE utf8_general_ci AFTER showdescription", packet_length=packet_length@entry=124)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_parse.cc:1300
#16 0x0000000000615f45 in do_command (thd=0x2f7aa00) at /usr/src/debug/mariadb-10.0.16/sql/sql_parse.cc:996
#17 0x00000000006ec7f4 in do_handle_one_connection (thd_arg=thd_arg@entry=0x2f7aa00)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_connect.cc:1375
#18 0x00000000006ec887 in handle_one_connection (arg=0x2f7aa00)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_connect.cc:1289
#19 0x00007fdf6d4be0a4 in start_thread () from /lib64/libpthread.so.0
#20 0x00007fdf6c3947fd in clone () from /lib64/libc.so.6#0  0x00007fdf6c2e4187 in raise () from /lib64/libc.so.6
#1  0x00007fdf6c2e5538 in abort () from /lib64/libc.so.6
#2  0x0000000000b1d4bb in sync_thread_add_level (latch=0x1dfd940 <dict_operation_lock>, level=1010, relock=0)
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/sync/sync0sync.cc:1287
#3  0x0000000000b1a315 in rw_lock_add_debug_info (lock=lock@entry=0x1dfd940 <dict_operation_lock>, pass=pass@entry=0, 
    lock_type=lock_type@entry=351, 
    file_name=file_name@entry=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc", line=line@entry=4181) at /usr/src/debug/mariadb-10.0.16/storage/xtradb/sync/sync0rw.cc:985
#4  0x0000000000b1b00a in rw_lock_x_lock_low (line=4181, 
    file_name=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc", pass=0, 
    high_priority=false, lock=0x1dfd940 <dict_operation_lock>)
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/sync/sync0rw.cc:738
#5  rw_lock_x_lock_func (lock=lock@entry=0x1dfd940 <dict_operation_lock>, pass=pass@entry=0, 
    file_name=file_name@entry=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc", line=line@entry=4181, priority_lock=priority_lock@entry=false, high_priority=high_priority@entry=false)
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/sync/sync0rw.cc:796
#6  0x0000000000accb96 in pfs_rw_lock_x_lock_func (lock=<optimized out>, pass=0, line=4181, 
    file_name=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc")
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/include/sync0rw.ic:890
#7  row_mysql_lock_data_dictionary_func (trx=0x7fdf08017688, 
    file=file@entry=0xe4d1b0 "/home/abuild/rpmbuild/BUILD/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc", 
    line=line@entry=4181) at /usr/src/debug/mariadb-10.0.16/storage/xtradb/row/row0mysql.cc:2184
#8  0x0000000000a06923 in rollback_inplace_alter_table (prebuilt=0x7fdf1003a8e8, table=0x7fdf10031470, 
    ha_alter_info=0x7fdf48264080) at /usr/src/debug/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc:4181
#9  ha_innobase::commit_inplace_alter_table (this=0x7fdf10036d68, altered_table=0x7fdf0800ed50, 
    ha_alter_info=0x7fdf48264080, commit=<optimized out>)
    at /usr/src/debug/mariadb-10.0.16/storage/xtradb/handler/handler0alter.cc:5431
#10 0x00000000006a07da in mysql_inplace_alter_table (target_mdl_request=0x7fdf482641b0, alter_ctx=0x7fdf48264d40, 
    inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, ha_alter_info=0x7fdf48264080, 
    altered_table=0x7fdf0800ed50, table=0x7fdf10031470, table_list=0x7fdf08005408, thd=0x7fdf10031470)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_table.cc:7140
#11 mysql_alter_table (thd=thd@entry=0x2f7aa00, new_db=<optimized out>, new_name=<optimized out>, 
    create_info=create_info@entry=0x7fdf48265920, table_list=table_list@entry=0x7fdf08005408, 
    alter_info=alter_info@entry=0x7fdf48265890, order_num=0, order=0x0, ignore=false)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_table.cc:8815
#12 0x00000000006efdd2 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x2f7aa00)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_alter.cc:312
#13 0x000000000060a12b in mysql_execute_command (thd=thd@entry=0x2f7aa00)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_parse.cc:5079
#14 0x0000000000613107 in mysql_parse (thd=thd@entry=0x2f7aa00, rawbuf=<optimized out>, length=124, 
    parser_state=parser_state@entry=0x7fdf482676b0) at /usr/src/debug/mariadb-10.0.16/sql/sql_parse.cc:6513
#15 0x0000000000614d33 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x2f7aa00, 
    packet=packet@entry=0x2f814b1 "ALTER TABLE test.mdl_course_modules ADD stefantest LONGTEXT CHARACTER SET utf8 COLLATE utf8_general_ci AFTER showdescription", packet_length=packet_length@entry=124)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_parse.cc:1300
#16 0x0000000000615f45 in do_command (thd=0x2f7aa00) at /usr/src/debug/mariadb-10.0.16/sql/sql_parse.cc:996
#17 0x00000000006ec7f4 in do_handle_one_connection (thd_arg=thd_arg@entry=0x2f7aa00)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_connect.cc:1375
#18 0x00000000006ec887 in handle_one_connection (arg=0x2f7aa00)
    at /usr/src/debug/mariadb-10.0.16/sql/sql_connect.cc:1289
#19 0x00007fdf6d4be0a4 in start_thread () from /lib64/libpthread.so.0
#20 0x00007fdf6c3947fd in clone () from /lib64/libc.so.6

I did dig even further and found that Innodb apparently gets into an infinite loop while
reserving free extents. (fsp_reserve_free_extents()) until mysqld aborts.

Comment by Nirbhay Choubey (Inactive) [ 2015-06-26 ]

MDEV-8142 (SUSE bug#930498) could be related to this issue.

Comment by Elena Stepanova [ 2015-06-26 ]

Remarkably, it only happens with XtraDB; InnoDB plugin works fine.

The MTR variation of the test case is obvious:

--source include/have_innodb.inc
 
 
drop database if exists moodle19;
create database moodle19;
use moodle19;
 
CREATE TABLE `mdl_course_modules` (
  `id` bigint(10) NOT NULL AUTO_INCREMENT,
  `course` bigint(10) NOT NULL DEFAULT '0',
  `module` bigint(10) NOT NULL DEFAULT '0',
  `instance` bigint(10) NOT NULL DEFAULT '0',
  `section` bigint(10) NOT NULL DEFAULT '0',
  `idnumber` varchar(100) DEFAULT NULL,
  `added` bigint(10) NOT NULL DEFAULT '0',
  `delay` varchar(10) NOT NULL DEFAULT '0',
  `score` smallint(4) NOT NULL DEFAULT '0',
  `indent` mediumint(5) NOT NULL DEFAULT '0',
  `visible` tinyint(1) NOT NULL DEFAULT '1',
  `checkboxesforprereqs` tinyint(1) NOT NULL DEFAULT '0',
  `stylewhencomplete` varchar(200) DEFAULT '',
  `checkboxforcomplete` tinyint(1) NOT NULL DEFAULT '0',
  `stylewhenlocked` varchar(200) DEFAULT 'locked',
  `visiblewhenlocked` tinyint(1) NOT NULL DEFAULT '1',
  `visibleold` tinyint(1) NOT NULL DEFAULT '1',
  `groupmode` smallint(4) NOT NULL DEFAULT '0',
  `groupingid` bigint(10) NOT NULL DEFAULT '0',
  `groupmembersonly` smallint(4) NOT NULL DEFAULT '0',
  `completion` tinyint(1) NOT NULL DEFAULT '0',
  `completiongradeitemnumber` bigint(10) DEFAULT NULL,
  `completionview` tinyint(1) NOT NULL DEFAULT '0',
  `completionexpected` bigint(10) NOT NULL DEFAULT '0',
  `availablefrom` bigint(10) NOT NULL DEFAULT '0',
  `availableuntil` bigint(10) NOT NULL DEFAULT '0',
  `showavailability` tinyint(1) NOT NULL DEFAULT '0',
  `showdescription` tinyint(1) NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`),
  KEY `mdl_courmodu_vis_ix` (`visible`),
  KEY `mdl_courmodu_cou_ix` (`course`),
  KEY `mdl_courmodu_mod_ix` (`module`),
  KEY `mdl_courmodu_ins_ix` (`instance`),
  KEY `mdl_courmodu_idncou_ix` (`idnumber`,`course`),
  KEY `mdl_courmodu_gro_ix` (`groupingid`)
) ENGINE=InnoDB AUTO_INCREMENT=447023 DEFAULT CHARSET=utf8 COMMENT='course_modules table retrofitted from MySQL';
 
let $num= 2701;
--disable_query_log
--echo # Inserting $num rows into the table...
while ($num) 
{
  eval INSERT INTO mdl_course_modules VALUES ($num,4,5,5,24,NULL,1141569781,'',0,0,1,0,'',0,'locked',1,1,0,0,0,0,NULL,0,0,0,0,0,0);
  dec $num;
}
--enable_query_log
ALTER TABLE moodle19.mdl_course_modules ADD stefantest LONGTEXT CHARACTER SET utf8 COLLATE utf8_general_ci AFTER showdescription;
 
drop database moodle19;

It also passes for innodb_plugin and hangs for xtradb.

Comment by Nirbhay Choubey (Inactive) [ 2015-07-10 ]

Looks like the following 2 patches for MDEV-6288 may have triggered it.
https://github.com/MariaDB/server/commit/6bd2f900b2681539a542d3639df3017f04f4279d.patch
https://github.com/MariaDB/server/commit/43c851435fb7da4c707a21797860232889702a4a.patch

The 3rd one for MDEV-6288 (pushed in mariadb-10.0.17), seemingly has fixed the issue.
https://github.com/MariaDB/server/commit/454beee5fbd9da8e87a54b46ea716679693361bd.patch

Generated at Thu Feb 08 07:26:46 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.