[MDEV-4479] SELECT from InnoDB table hangs in dyn_array_get_element being executed in parallel with replicating LOAD DATA - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.0.2, 5.5.30
Fix Version/s: 10.0.8
Component/s: Storage Engine - InnoDB
Labels:
- upstream-fixed

Description

Also reproducible on MySQL 5.6, 5.7 (didn't try 5.5) and filed as http://bugs.mysql.com/bug.php?id=69141

Reproducible on debug builds, not sure if it's because the issue is debug-specific, or just because release builds are too fast for that.

The provided test case hangs on the next SELECT COUNT after executing several of them reasonably fast (and returning 0).
It stays in this state even when replicating of LOAD DATA ends:

MariaDB [test]> show processlist;

+----+-------------+-----------------+------+---------+------+-----------------------------------------------------------------------------+-------------------------+----------+

| Id | User        | Host            | db   | Command | Time | State                                                                       | Info                    | Progress |

+----+-------------+-----------------+------+---------+------+-----------------------------------------------------------------------------+-------------------------+----------+

|  2 | root        | localhost:55696 | test | Sleep   |  252 |                                                                             | NULL                    |    0.000 |

|  3 | root        | localhost:55697 | test | Sleep   |  252 |                                                                             | NULL                    |    0.000 |

|  6 | root        | localhost:55703 | test | Query   |  145 | Sending data                                                                | SELECT COUNT(*) FROM t1 |    0.000 |

|  7 | root        | localhost:55704 | test | Sleep   |  252 |                                                                             | NULL                    |    0.000 |

|  8 | system user |                 | NULL | Connect |  252 | Waiting for master to send event                                            | NULL                    |    0.000 |

|  9 | system user |                 | NULL | Connect |  252 | Slave has read all relay log; waiting for the slave I/O thread to update it | NULL                    |    0.000 |

| 10 | root        | localhost:55708 | test | Query   |    0 | NULL                                                                        | show processlist        |    0.000 |

+----+-------------+-----------------+------+---------+------+-----------------------------------------------------------------------------+-------------------------+----------+

Stack trace from the server with the hanging query:

#0  dyn_block_get_used (block=0x7fdc2402bf18) at 10.0-base/storage/xtradb/include/dyn0dyn.ic:100

#1  0x0000000000ae69fe in dyn_array_get_element (arr=0x7fdc7fb3ae88, pos=27088) at 10.0-base/storage/xtradb/include/dyn0dyn.ic:300

#2  0x0000000000ab63c6 in mtr_memo_contains (mtr=0x7fdc7fb3ae80, object=0x7fdc6cfd0700, type=2) at 10.0-base/storage/xtradb/include/mtr0mtr.ic:163

#3  0x0000000000ab72bc in mtr_memo_contains_page (mtr=0x7fdc7fb3ae80, ptr=0x7fdc6f9cc37b "", type=2) at 10.0-base/storage/xtradb/mtr/mtr0mtr.c:369

#4  0x00000000009e3d46 in row_vers_build_for_consistent_read (rec=0x7fdc6f9cc37b "", mtr=0x7fdc7fb3ae80, index=0x7fdc2c01f928, offsets=0x7fdc7fb3adc0, view=0x7fdc24013c68, offset_heap=0x7fdc7fb3adb8, in_heap=0x7fdc240245f0, old_vers=0x7fdc7fb3adc8) at 10.0-base/storage/xtradb/row/row0vers.c:502

#5  0x00000000009d9bfd in row_sel_build_prev_vers_for_mysql (read_view=0x7fdc24013c68, clust_index=0x7fdc2c01f928, prebuilt=0x7fdc24020718, rec=0x7fdc6f9cc37b "", offsets=0x7fdc7fb3adc0, offset_heap=0x7fdc7fb3adb8, old_vers=0x7fdc7fb3adc8, mtr=0x7fdc7fb3ae80) at 10.0-base/storage/xtradb/row/row0sel.c:2909

#6  0x00000000009dcec2 in row_search_for_mysql (buf=0x7fdc24019f48 "\377", ' ' <repeats 128 times>"\245, \245\245\245\245\245\245\377\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245"..., mode=1, prebuilt=0x7fdc24020718, match_mode=0, direction=0) at 10.0-base/storage/xtradb/row/row0sel.c:4536

#7  0x00000000009a226e in ha_innobase::index_read (this=0x7fdc2401e6e8, buf=0x7fdc24019f48 "\377", ' ' <repeats 128 times>"\245, \245\245\245\245\245\245\377\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245"..., key_ptr=0x0, key_len=0, find_flag=HA_READ_AFTER_KEY) at 10.0-base/storage/xtradb/handler/ha_innodb.cc:7103

#8  0x00000000009a2eae in ha_innobase::index_first (this=0x7fdc2401e6e8, buf=0x7fdc24019f48 "\377", ' ' <repeats 128 times>"\245, \245\245\245\245\245\245\377\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245"...) at 10.0-base/storage/xtradb/handler/ha_innodb.cc:7454

#9  0x00000000009a3096 in ha_innobase::rnd_next (this=0x7fdc2401e6e8, buf=0x7fdc24019f48 "\377", ' ' <repeats 128 times>"\245, \245\245\245\245\245\245\377\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245"...) at 10.0-base/storage/xtradb/handler/ha_innodb.cc:7551

#10 0x00000000005b0aca in handler::ha_rnd_next (this=0x7fdc2401e6e8, buf=0x7fdc24019f48 "\377", ' ' <repeats 128 times>"\245, \245\245\245\245\245\245\377\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245"...) at 10.0-base/sql/sql_class.h:4468

#11 0x00000000009144e4 in rr_sequential (info=0x7fdc24009040) at 10.0-base/sql/records.cc:458

#12 0x0000000000674762 in join_init_read_record (tab=0x7fdc24008f90) at 10.0-base/sql/sql_select.cc:17673

#13 0x00000000006727d1 in sub_select (join=0x7fdc24008050, join_tab=0x7fdc24008f90, end_of_records=false) at 10.0-base/sql/sql_select.cc:16785

#14 0x00000000006720ec in do_select (join=0x7fdc24008050, fields=0x7fdc24008410, table=0x0, procedure=0x0) at 10.0-base/sql/sql_select.cc:16458

#15 0x000000000065125b in JOIN::exec_inner (this=0x7fdc24008050) at 10.0-base/sql/sql_select.cc:3005

#16 0x000000000064e5d9 in JOIN::exec (this=0x7fdc24008050) at 10.0-base/sql/sql_select.cc:2296

#17 0x0000000000651afd in mysql_select (thd=0x3db0e10, rref_pointer_array=0x3db3e08, tables=0x7fdc240079b8, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7fdc24008030, unit=0x3db34d0, select_lex=0x3db3ba8) at 10.0-base/sql/sql_select.cc:3233

#18 0x0000000000648403 in handle_select (thd=0x3db0e10, lex=0x3db3418, result=0x7fdc24008030, setup_tables_done_option=0) at 10.0-base/sql/sql_select.cc:376

#19 0x000000000061e401 in execute_sqlcom_select (thd=0x3db0e10, all_tables=0x7fdc240079b8) at 10.0-base/sql/sql_parse.cc:4804

#20 0x0000000000616aab in mysql_execute_command (thd=0x3db0e10) at 10.0-base/sql/sql_parse.cc:2268

#21 0x0000000000620c6b in mysql_parse (thd=0x3db0e10, rawbuf=0x7fdc24007708 "select count(*) from t2", length=23, parser_state=0x7fdc7fb3c570) at 10.0-base/sql/sql_parse.cc:5927

#22 0x0000000000613de6 in dispatch_command (command=COM_QUERY, thd=0x3db0e10, packet=0x3db4be1 "", packet_length=23) at 10.0-base/sql/sql_parse.cc:1091

#23 0x0000000000613315 in do_command (thd=0x3db0e10) at 10.0-base/sql/sql_parse.cc:810

#24 0x000000000072860e in do_handle_one_connection (thd_arg=0x3db0e10) at 10.0-base/sql/sql_connect.cc:1266

#25 0x000000000072837c in handle_one_connection (arg=0x3db0e10) at 10.0-base/sql/sql_connect.cc:1181

#26 0x00007fdc7f1dae9a in start_thread (arg=0x7fdc7fb3d700) at pthread_create.c:308

#27 0x00007fdc7e4cecbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Stack trace is from

revision-id: knielsen@knielsen-hq.org-20130503092729-gedp152b19k5wdnj

revno: 3626

branch-nick: 10.0-base

Test case:

--source include/master-slave.inc

--source include/have_innodb.inc

--connection master

--perl

open (LOAD, ">$ENV{MYSQLTEST_VARDIR}/1.load") || die "Could not create load file\n";

foreach (1..1000000) {

	print LOAD "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa\n";

close (LOAD);

EOF

CREATE TABLE t1 (c CHAR(128)) ENGINE=InnoDB;

eval LOAD DATA LOCAL INFILE '$MYSQLTEST_VARDIR/1.load' INTO TABLE t1;

--connection slave

--let $run = 100

while ($run)

	SELECT COUNT(*) FROM t1;

	sleep 1;

	dec $run;

Reproducible with InnoDB and XtraDB.

Attachments

Issue Links

relates to

MDEV-7056 Upstream bug reports and test cases

Closed

links to

Bug #69141 - SELECT from InnoDB table hangs being run in parallel with replicating LOAD DATA

SELECT from InnoDB table hangs in dyn_array_get_element being executed in parallel with replicating LOAD DATA

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration