[#MDEV-14625] [Draft] Assertion `!rw_lock_own(btr_get_search_latch(index), RW_LOCK_X)' failed in btr_search_info

10.3 70d6c944cbc1a7
mysqld: /data/src/10.3/storage/innobase/include/btr0sea.ic:66: void btr_search_info_update(dict_index_t, btr_cur_t): Assertion `!rw_lock_own(btr_get_search_latch(index), RW_LOCK_X)' failed.
171211 20:11:29 [ERROR] mysqld got signal 6 ;

Server version: 10.3.3-MariaDB-debug-log
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=8
max_threads=153
thread_count=14
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467412 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7fd09c000b00
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 = 0x7fd0fd74eec0 thread_stack 0x49000
/data/bld/10.3/bin/mysqld(my_print_stacktrace+0x40)[0x56460f4bfe84]
/data/bld/10.3/bin/mysqld(handle_fatal_signal+0x3a8)[0x56460ece1a9b]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x110c0)[0x7fd116c3c0c0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcf)[0x7fd114f62fcf]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7fd114f643fa]
/lib/x86_64-linux-gnu/libc.so.6(+0x2be37)[0x7fd114f5be37]
mysys/stacktrace.c:269(my_print_stacktrace)[0x7fd114f5bee2]
include/btr0sea.ic:68(btr_search_info_update(dict_index_t, btr_cur_t))[0x56460f2803ef]
btr/btr0cur.cc:2193(btr_cur_search_to_nth_level(dict_index_t, unsigned long, dtuple_t const, page_cur_mode_t, unsigned long, btr_cur_t, unsigned long, char const, unsigned int, mtr_t*, unsigned long))[0x56460f28666b]
include/btr0pcur.ic:459(btr_pcur_open_low(dict_index_t, unsigned long, dtuple_t const, page_cur_mode_t, unsigned long, btr_pcur_t, char const, unsigned int, unsigned long, mtr_t*))[0x56460f19dbd0]
row/row0row.cc:1115(row_search_index_entry(dict_index_t, dtuple_t const, unsigned long, btr_pcur_t, mtr_t))[0x56460f1a08e3]
row/row0upd.cc:2392(row_upd_sec_index_entry(upd_node_t, que_thr_t))[0x56460f1d5455]
row/row0upd.cc:2549(row_upd_sec_step(upd_node_t, que_thr_t))[0x56460f1d5dce]
row/row0upd.cc:3306(row_upd(upd_node_t, que_thr_t))[0x56460f1d85b2]
row/row0upd.cc:3421(row_upd_step(que_thr_t*))[0x56460f1d8920]
row/row0mysql.cc:1976(row_update_for_mysql(row_prebuilt_t*))[0x56460f173116]
handler/ha_innodb.cc:9140(ha_innobase::update_row(unsigned char const, unsigned char const))[0x56460f018aaa]
sql/handler.cc:6098(handler::ha_update_row(unsigned char const, unsigned char const))[0x56460ecf1fe3]
sql/sql_update.cc:884(mysql_update(THD, TABLE_LIST, List<Item>&, List<Item>&, Item, unsigned int, st_order, unsigned long long, enum_duplicates, bool, unsigned long long, unsigned long long))[0x56460eb0c08f]
sql/sql_parse.cc:4555(mysql_execute_command(THD*))[0x56460ea1d1cf]
sql/sql_parse.cc:7959(mysql_parse(THD, char, unsigned int, Parser_state*, bool, bool))[0x56460ea27ede]
sql/sql_parse.cc:1830(dispatch_command(enum_server_command, THD, char, unsigned int, bool, bool))[0x56460ea1581a]
sql/sql_parse.cc:1370(do_command(THD*))[0x56460ea1423b]
sql/sql_connect.cc:1420(do_handle_one_connection(CONNECT*))[0x56460eb6cb9c]
sql/sql_connect.cc:1327(handle_one_connection)[0x56460eb6c929]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7494)[0x7fd116c32494]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fd11501893f]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7fd09c0158c8): UPDATE table11_innodb SET `col_int_key` = 3 /* QNO 28041 CON_ID 14 */
Connection ID (thread ID): 14
Status: NOT_KILLED

#7  0x00007fd114f5bee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6

#8  0x000056460f2803ef in btr_search_info_update (index=0x7fd09c40de58, cursor=0x7fd0fd74c2b0) at /data/src/10.3/storage/innobase/include/btr0sea.ic:66

#9  0x000056460f28666b in btr_cur_search_to_nth_level (index=0x7fd09c40de58, level=0, tuple=0x7fd09c1f2878, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7fd0fd74c2b0, has_search_latch=0, file=0x56460f7d72f0 "/data/src/10.3/storage/innobase/row/row0row.cc", line=1115, mtr=0x7fd0fd74c7d0, autoinc=0) at /data/src/10.3/storage/innobase/btr/btr0cur.cc:2190

#10 0x000056460f19dbd0 in btr_pcur_open_low (index=0x7fd09c40de58, level=0, tuple=0x7fd09c1f2878, mode=PAGE_CUR_LE, latch_mode=2, cursor=0x7fd0fd74c2b0, file=0x56460f7d72f0 "/data/src/10.3/storage/innobase/row/row0row.cc", line=1115, autoinc=0, mtr=0x7fd0fd74c7d0) at /data/src/10.3/storage/innobase/include/btr0pcur.ic:459

#11 0x000056460f1a08e3 in row_search_index_entry (index=0x7fd09c40de58, entry=0x7fd09c1f2878, mode=2, pcur=0x7fd0fd74c2b0, mtr=0x7fd0fd74c7d0) at /data/src/10.3/storage/innobase/row/row0row.cc:1115

#12 0x000056460f1d5455 in row_upd_sec_index_entry (node=0x7fd09c09d3f8, thr=0x7fd09c09d728) at /data/src/10.3/storage/innobase/row/row0upd.cc:2392

#13 0x000056460f1d5dce in row_upd_sec_step (node=0x7fd09c09d3f8, thr=0x7fd09c09d728) at /data/src/10.3/storage/innobase/row/row0upd.cc:2549

#14 0x000056460f1d85b2 in row_upd (node=0x7fd09c09d3f8, thr=0x7fd09c09d728) at /data/src/10.3/storage/innobase/row/row0upd.cc:3306

#15 0x000056460f1d8920 in row_upd_step (thr=0x7fd09c09d728) at /data/src/10.3/storage/innobase/row/row0upd.cc:3421

#16 0x000056460f173116 in row_update_for_mysql (prebuilt=0x7fd09c09cc18) at /data/src/10.3/storage/innobase/row/row0mysql.cc:1974

#17 0x000056460f018aaa in ha_innobase::update_row (this=0x7fd09c2ccd48, old_row=0x7fd09c118318 <incomplete sequence \371>, new_row=0x7fd09c118308 "\371\003") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:9140

#18 0x000056460ecf1fe3 in handler::ha_update_row (this=0x7fd09c2ccd48, old_data=0x7fd09c118318 <incomplete sequence \371>, new_data=0x7fd09c118308 "\371\003") at /data/src/10.3/sql/handler.cc:6098

#19 0x000056460eb0c08f in mysql_update (thd=0x7fd09c000b00, table_list=0x7fd09c015a10, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551612, handle_duplicates=DUP_ERROR, ignore=false, found_return=0x7fd0fd74d7b0, updated_return=0x7fd0fd74d860) at /data/src/10.3/sql/sql_update.cc:884

#20 0x000056460ea1d1cf in mysql_execute_command (thd=0x7fd09c000b00) at /data/src/10.3/sql/sql_parse.cc:4555

#21 0x000056460ea27ede in mysql_parse (thd=0x7fd09c000b00, rawbuf=0x7fd09c0158c8 "UPDATE table11_innodb SET `col_int_key` = 3 /* QNO 28041 CON_ID 14 */", length=69, parser_state=0x7fd0fd74e660, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7959

#22 0x000056460ea1581a in dispatch_command (command=COM_QUERY, thd=0x7fd09c000b00, packet=0x7fd09c00af41 " UPDATE table11_innodb SET `col_int_key` = 3 /* QNO 28041 CON_ID 14 */ ", packet_length=71, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1828

#23 0x000056460ea1423b in do_command (thd=0x7fd09c000b00) at /data/src/10.3/sql/sql_parse.cc:1370

#24 0x000056460eb6cb9c in do_handle_one_connection (connect=0x564612808d60) at /data/src/10.3/sql/sql_connect.cc:1420

#25 0x000056460eb6c929 in handle_one_connection (arg=0x564612808d60) at /data/src/10.3/sql/sql_connect.cc:1326

#26 0x00007fd116c32494 in start_thread (arg=0x7fd0fd74f700) at pthread_create.c:333

#27 0x00007fd11501893f in clone () from /lib/x86_64-linux-gnu/libc.so.6

All threads' stack trace from the assertion failure is attached as assertion_failure_threads.

It happened upon a concurrent test. Not easily reproducible.

perl ./run-scenario.pl --grammar=conf/runtime/metadata_stability.yy --gendata=conf/runtime/metadata_stability.zz --duration=400 --threads=6 --queries=100M --redefine=conf/mariadb/instant_add.yy --mysqld=--max-statement-time=30 --reporters=Backtrace,ErrorLog,Deadlock --scenario=Restart --engine=InnoDB --mysqld=--innodb_stats_persistent=0 --seed=1512966342 --basedir=/data/bld/10.3 --vardir=/dev/shm/vardir1

General log is attached.

While trying to reproduce it, I got a hang instead.

2017-12-11 21:11:21 19 [Note] InnoDB: Deleting the meta-data file './test/t14.cfg'

2017-12-11 21:11:21 19 [Note] InnoDB: Resuming purge

2017-12-11 21:15:24 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710695130880 has waited at row0purge.cc line 928 for 241.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:24 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140711278212864 has waited at ha_innodb.cc line 5937 for 241.00 seconds the semaphore:

Mutex at 0x55e4d3621290, Mutex DICT_SYS created dict0dict.cc:1098, lock var 2

Last time reserved in file /data/src/10.3/storage/innobase/row/row0mysql.cc line 2364

2017-12-11 21:15:24 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710703523584 has waited at row0purge.cc line 928 for 241.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:24 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710711916288 has waited at row0purge.cc line 928 for 241.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:24 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140711278515968 has waited at btr0sea.ic line 114 for 241.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d309e340 created in file btr0sea.cc line 260

a writer (thread id 140711279425280) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file btr0sea.ic line 152

Last time write locked in file btr0sea.ic line 96

2017-12-11 21:15:24 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710923409152 has waited at row0purge.cc line 928 for 241.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:24 0 [Note] InnoDB: A semaphore wait:

--Thread 140710931801856 has waited at srv0srv.cc line 2120 for 240.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:24 0 [Note] InnoDB: A semaphore wait:

--Thread 140710695130880 has waited at row0purge.cc line 928 for 241.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:24 0 [Note] InnoDB: A semaphore wait:

--Thread 140711278212864 has waited at ha_innodb.cc line 5937 for 241.00 seconds the semaphore:

Mutex at 0x55e4d3621290, Mutex DICT_SYS created dict0dict.cc:1098, lock var 2

Last time reserved in file /data/src/10.3/storage/innobase/row/row0mysql.cc line 2364

2017-12-11 21:15:24 0 [Note] InnoDB: A semaphore wait:

--Thread 140710703523584 has waited at row0purge.cc line 928 for 241.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:24 0 [Note] InnoDB: A semaphore wait:

--Thread 140710711916288 has waited at row0purge.cc line 928 for 241.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:24 0 [Note] InnoDB: A semaphore wait:

--Thread 140711278515968 has waited at btr0sea.ic line 114 for 241.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d309e340 created in file btr0sea.cc line 260

a writer (thread id 140711279425280) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file btr0sea.ic line 152

Last time write locked in file btr0sea.ic line 96

2017-12-11 21:15:24 0 [Note] InnoDB: A semaphore wait:

--Thread 140710923409152 has waited at row0purge.cc line 928 for 241.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:

InnoDB: Pending reads 0, writes 0

=====================================

2017-12-11 21:15:30 0x7ff9d29b5700 INNODB MONITOR OUTPUT

=====================================

Per second averages calculated from the last 35 seconds

-----------------

BACKGROUND THREAD

-----------------

srv_master_thread loops: 45 srv_active, 0 srv_shutdown, 49 srv_idle

srv_master_thread log flush and writes: 93

----------

SEMAPHORES

----------

-------------

RW-LATCH INFO

-------------

RW-LOCK: 0x55e4d36211d0  (1 waiters)

Locked: thread 140711278515968 file handler0alter.cc line 9172  X-LOCK

RW-LOCK: 0x55e4d309e340  (1 waiters)

Locked: thread 140711279425280 file btr0sea.ic line 96  X-LOCK

RW-LOCK: 0x55e4d309e180

Locked: thread 140711278515968 file btr0sea.ic line 114  X-LOCK

RW-LOCK: 0x55e4d309dfc0

Locked: thread 140711278515968 file btr0sea.ic line 114  X-LOCK

RW-LOCK: 0x55e4d309de00

Locked: thread 140711278515968 file btr0sea.ic line 114  X-LOCK

RW-LOCK: 0x55e4d309dc40

Locked: thread 140711278515968 file btr0sea.ic line 114  X-LOCK

RW-LOCK: 0x55e4d309da80

Locked: thread 140711278515968 file btr0sea.ic line 114  X-LOCK

Total number of rw-locks 16551

OS WAIT ARRAY INFO: reservation count 21868

--Thread 140710931801856 has waited at srv0srv.cc line 2120 for 246.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

--Thread 140710695130880 has waited at row0purge.cc line 928 for 247.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

--Thread 140711278212864 has waited at ha_innodb.cc line 5937 for 247.00 seconds the semaphore:

Mutex at 0x55e4d3621290, Mutex DICT_SYS created dict0dict.cc:1098, lock var 2

Last time reserved in file /data/src/10.3/storage/innobase/row/row0mysql.cc line 2364

--Thread 140710703523584 has waited at row0purge.cc line 928 for 247.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

--Thread 140710711916288 has waited at row0purge.cc line 928 for 247.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

--Thread 140711278515968 has waited at btr0sea.ic line 114 for 247.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d309e340 created in file btr0sea.cc line 260

a writer (thread id 140711279425280) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file btr0sea.ic line 152

Last time write locked in file btr0sea.ic line 96

--Thread 140710923409152 has waited at row0purge.cc line 928 for 247.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

OS WAIT ARRAY INFO: signal count 16163

RW-shared spins 0, rounds 29983, OS waits 10368

RW-excl spins 0, rounds 97931, OS waits 2555

RW-sx spins 4, rounds 76, OS waits 0

Spin rounds per wait: 29983.00 RW-shared, 97931.00 RW-excl, 19.00 RW-sx

------------

TRANSACTIONS

------------

Trx id counter 21649

Purge done for trx's n:o < 21648 undo n:o < 0 state: running

History list length 25

Total number of lock structs in row lock hash table 0

LIST OF TRANSACTIONS FOR EACH SESSION:

---TRANSACTION 422186629261816, not started

0 lock struct(s), heap size 1160, 0 row lock(s)

---TRANSACTION 422186629260744, not started

0 lock struct(s), heap size 1160, 0 row lock(s)

---TRANSACTION 422186629258600, not started

0 lock struct(s), heap size 1160, 0 row lock(s)

---TRANSACTION 422186629259672, not started

mysql tables in use 1, locked 1

0 lock struct(s), heap size 1160, 0 row lock(s)

---TRANSACTION 422186629257528, not started

mysql tables in use 1, locked 1

0 lock struct(s), heap size 1160, 0 row lock(s)

---TRANSACTION 422186629256456, not started

0 lock struct(s), heap size 1160, 0 row lock(s)

---TRANSACTION 422186629255384, not started

0 lock struct(s), heap size 1160, 0 row lock(s)

--------

FILE I/O

--------

I/O thread 0 state: waiting for completed aio requests (insert buffer thread)

I/O thread 1 state: waiting for completed aio requests (log thread)

I/O thread 2 state: waiting for completed aio requests (read thread)

I/O thread 3 state: waiting for completed aio requests (read thread)

I/O thread 4 state: waiting for completed aio requests (read thread)

I/O thread 5 state: waiting for completed aio requests (read thread)

I/O thread 6 state: waiting for completed aio requests (write thread)

I/O thread 7 state: waiting for completed aio requests (write thread)

I/O thread 8 state: waiting for completed aio requests (write thread)

I/O thread 9 state: waiting for completed aio requests (write thread)

Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,

 ibuf aio reads:, log i/o's:, sync i/o's:

Pending flushes (fsync) log: 0; buffer pool: 0

180 OS file reads, 20815 OS file writes, 13662 OS fsyncs

0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s

-------------------------------------

INSERT BUFFER AND ADAPTIVE HASH INDEX

-------------------------------------

Ibuf: size 1, free list len 0, seg size 2, 0 merges

merged operations:

 insert 0, delete mark 0, delete 0

discarded operations:

 insert 0, delete mark 0, delete 0

InnoDB: ###### Diagnostic info printed to the standard error stream

2017-12-11 21:15:55 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710931801856 has waited at srv0srv.cc line 2120 for 271.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:55 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710695130880 has waited at row0purge.cc line 928 for 272.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:55 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140711278212864 has waited at ha_innodb.cc line 5937 for 272.00 seconds the semaphore:

Mutex at 0x55e4d3621290, Mutex DICT_SYS created dict0dict.cc:1098, lock var 2

Last time reserved in file /data/src/10.3/storage/innobase/row/row0mysql.cc line 2364

2017-12-11 21:15:55 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710703523584 has waited at row0purge.cc line 928 for 272.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:55 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710711916288 has waited at row0purge.cc line 928 for 272.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:55 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140711278515968 has waited at btr0sea.ic line 114 for 272.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d309e340 created in file btr0sea.cc line 260

a writer (thread id 140711279425280) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file btr0sea.ic line 152

Last time write locked in file btr0sea.ic line 96

2017-12-11 21:15:55 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710923409152 has waited at row0purge.cc line 928 for 272.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:55 0 [Note] InnoDB: A semaphore wait:

--Thread 140710931801856 has waited at srv0srv.cc line 2120 for 271.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:55 0 [Note] InnoDB: A semaphore wait:

--Thread 140710956979968 has waited at srv0srv.cc line 1306 for 25.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d309da80 created in file btr0sea.cc line 260

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file btr0sea.ic line 152

Last time write locked in file btr0sea.ic line 114

2017-12-11 21:15:55 0 [Note] InnoDB: A semaphore wait:

--Thread 140710695130880 has waited at row0purge.cc line 928 for 272.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:55 0 [Note] InnoDB: A semaphore wait:

--Thread 140711278212864 has waited at ha_innodb.cc line 5937 for 272.00 seconds the semaphore:

Mutex at 0x55e4d3621290, Mutex DICT_SYS created dict0dict.cc:1098, lock var 2

Last time reserved in file /data/src/10.3/storage/innobase/row/row0mysql.cc line 2364

2017-12-11 21:15:55 0 [Note] InnoDB: A semaphore wait:

--Thread 140710703523584 has waited at row0purge.cc line 928 for 272.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:55 0 [Note] InnoDB: A semaphore wait:

--Thread 140710711916288 has waited at row0purge.cc line 928 for 272.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:15:55 0 [Note] InnoDB: A semaphore wait:

--Thread 140711278515968 has waited at btr0sea.ic line 114 for 272.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d309e340 created in file btr0sea.cc line 260

a writer (thread id 140711279425280) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file btr0sea.ic line 152

Last time write locked in file btr0sea.ic line 96

2017-12-11 21:15:55 0 [Note] InnoDB: A semaphore wait:

--Thread 140710923409152 has waited at row0purge.cc line 928 for 272.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:

InnoDB: Pending reads 0, writes 0

InnoDB: ###### Diagnostic info printed to the standard error stream

2017-12-11 21:16:26 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710931801856 has waited at srv0srv.cc line 2120 for 302.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:16:26 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710695130880 has waited at row0purge.cc line 928 for 303.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:16:26 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140711278212864 has waited at ha_innodb.cc line 5937 for 303.00 seconds the semaphore:

Mutex at 0x55e4d3621290, Mutex DICT_SYS created dict0dict.cc:1098, lock var 2

Last time reserved in file /data/src/10.3/storage/innobase/row/row0mysql.cc line 2364

2017-12-11 21:16:26 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710703523584 has waited at row0purge.cc line 928 for 303.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:16:26 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710711916288 has waited at row0purge.cc line 928 for 303.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:16:26 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140711278515968 has waited at btr0sea.ic line 114 for 303.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d309e340 created in file btr0sea.cc line 260

a writer (thread id 140711279425280) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file btr0sea.ic line 152

Last time write locked in file btr0sea.ic line 96

2017-12-11 21:16:26 0 [Warning] InnoDB: A long semaphore wait:

--Thread 140710923409152 has waited at row0purge.cc line 928 for 303.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:16:26 0 [Note] InnoDB: A semaphore wait:

--Thread 140710931801856 has waited at srv0srv.cc line 2120 for 302.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:16:26 0 [Note] InnoDB: A semaphore wait:

--Thread 140710956979968 has waited at srv0srv.cc line 1306 for 56.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d309da80 created in file btr0sea.cc line 260

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file btr0sea.ic line 152

Last time write locked in file btr0sea.ic line 114

2017-12-11 21:16:26 0 [Note] InnoDB: A semaphore wait:

--Thread 140710695130880 has waited at row0purge.cc line 928 for 303.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:16:26 0 [Note] InnoDB: A semaphore wait:

--Thread 140711278212864 has waited at ha_innodb.cc line 5937 for 303.00 seconds the semaphore:

Mutex at 0x55e4d3621290, Mutex DICT_SYS created dict0dict.cc:1098, lock var 2

Last time reserved in file /data/src/10.3/storage/innobase/row/row0mysql.cc line 2364

2017-12-11 21:16:26 0 [Note] InnoDB: A semaphore wait:

--Thread 140710703523584 has waited at row0purge.cc line 928 for 303.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:16:26 0 [Note] InnoDB: A semaphore wait:

--Thread 140710711916288 has waited at row0purge.cc line 928 for 303.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

2017-12-11 21:16:26 0 [Note] InnoDB: A semaphore wait:

--Thread 140711278515968 has waited at btr0sea.ic line 114 for 303.00 seconds the semaphore:

X-lock on RW-latch at 0x55e4d309e340 created in file btr0sea.cc line 260

a writer (thread id 140711279425280) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file btr0sea.ic line 152

Last time write locked in file btr0sea.ic line 96

2017-12-11 21:16:26 0 [Note] InnoDB: A semaphore wait:

--Thread 140710923409152 has waited at row0purge.cc line 928 for 303.00 seconds the semaphore:

S-lock on RW-latch at 0x55e4d36211d0 created in file dict0dict.cc line 1109

a writer (thread id 140711278515968) has reserved it in mode  exclusive

number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0purge.cc line 928

Last time write locked in file handler0alter.cc line 9172

InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:

InnoDB: Pending reads 0, writes 0

InnoDB: ###### Diagnostic info printed to the standard error stream

It started complaining about long semaphore wait as above, but then it stopped and just kept hanging.

Thread 4 (Thread 0x7ff9e5c59700 (LWP 1122)):

#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185

#1  0x000055e4d099513a in os_event::wait (this=0x55e4d309e400) at /data/src/10.3/storage/innobase/os/os0event.cc:166

#2  0x000055e4d0994b49 in os_event::wait_low (this=0x55e4d309e400, reset_sig_count=2) at /data/src/10.3/storage/innobase/os/os0event.cc:336

#3  0x000055e4d0994eef in os_event_wait_low (event=0x55e4d309e400, reset_sig_count=2) at /data/src/10.3/storage/innobase/os/os0event.cc:535

#4  0x000055e4d0aa5b08 in sync_array_wait_event (arr=0x55e4d2975530, cell=@0x7ff9e5c54788: 0x55e4d2975840) at /data/src/10.3/storage/innobase/sync/sync0arr.cc:475

#5  0x000055e4d0aa92dd in rw_lock_x_lock_func (lock=0x55e4d309e340, pass=0, file_name=0x55e4d10e66c8 "/data/src/10.3/storage/innobase/include/btr0sea.ic", line=114) at /data/src/10.3/stora

ge/innobase/sync/sync0rw.cc:767

#6  0x000055e4d0b4eb5e in pfs_rw_lock_x_lock_func (lock=0x55e4d309e340, pass=0, file_name=0x55e4d10e66c8 "/data/src/10.3/storage/innobase/include/btr0sea.ic", line=114) at /data/src/10.3/s

torage/innobase/include/sync0rw.ic:573

#7  0x000055e4d0b52b9e in btr_search_x_lock_all () at /data/src/10.3/storage/innobase/include/btr0sea.ic:114

#8  0x000055e4d0b539be in btr_search_enable () at /data/src/10.3/storage/innobase/btr/btr0sea.cc:438

#9  0x000055e4d0908226 in ha_innobase::commit_inplace_alter_table (this=0x7ff97014a5a8, altered_table=0x7ff97012be90, ha_alter_info=0x7ff9e5c55570, commit=true) at /data/src/10.3/storage/innobase/handler/handler0alter.cc:9564

#10 0x000055e4d059b3da in handler::ha_commit_inplace_alter_table (this=0x7ff97014a5a8, altered_table=0x7ff97012be90, ha_alter_info=0x7ff9e5c55570, commit=true) at /data/src/10.3/sql/handler.cc:4251

#11 0x000055e4d039ac98 in mysql_inplace_alter_table (thd=0x7ff970000b00, table_list=0x7ff970029ed0, table=0x7ff9701293d0, altered_table=0x7ff97012be90, ha_alter_info=0x7ff9e5c55570, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7ff9e5c555e0, alter_ctx=0x7ff9e5c561a0) at /data/src/10.3/sql/sql_table.cc:7261

#12 0x000055e4d039ff7c in mysql_alter_table (thd=0x7ff970000b00, new_db=0x7ff97002a4e0 "test", new_name=0x0, create_info=0x7ff9e5c56db0, table_list=0x7ff970029ed0, alter_info=0x7ff9e5c56d00, order_num=0, order=0x0, ignore=false) at /data/src/10.3/sql/sql_table.cc:9237

#13 0x000055e4d0420023 in Sql_cmd_alter_table::execute (this=0x7ff97002a738, thd=0x7ff970000b00) at /data/src/10.3/sql/sql_alter.cc:331

#14 0x000055e4d02d14da in mysql_execute_command (thd=0x7ff970000b00) at /data/src/10.3/sql/sql_parse.cc:6245

#15 0x000055e4d02d5ede in mysql_parse (thd=0x7ff970000b00, rawbuf=0x7ff970029d48 "ALTER TABLE t20 ADD COLUMN IF NOT EXISTS vcol7 DATE AS ( tcol4 ) VIRTUAL, LOCK=SHARED /* QNO 11141 CON_ID 17 */", length=111, parser_state=0x7ff9e5c58660, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7959

#16 0x000055e4d02c381a in dispatch_command (command=COM_QUERY, thd=0x7ff970000b00, packet=0x7ff97000b041 "ALTER TABLE t20 ADD COLUMN IF NOT EXISTS vcol7 DATE AS ( tcol4 ) VIRTUAL, LOCK=SHARED /* QNO 11141 CON_ID 17 */", packet_length=111, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1828

#17 0x000055e4d02c223b in do_command (thd=0x7ff970000b00) at /data/src/10.3/sql/sql_parse.cc:1370

#18 0x000055e4d041ab9c in do_handle_one_connection (connect=0x55e4d3370e60) at /data/src/10.3/sql/sql_connect.cc:1420

#19 0x000055e4d041a929 in handle_one_connection (arg=0x55e4d3370e60) at /data/src/10.3/sql/sql_connect.cc:1326

#20 0x00007ff9ff17d494 in start_thread (arg=0x7ff9e5c59700) at pthread_create.c:333

#21 0x00007ff9fd56393f in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 3 (Thread 0x7ff9e5c0f700 (LWP 1123)):

#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185

#1  0x000055e4d099513a in os_event::wait (this=0x55e4d36213a0) at /data/src/10.3/storage/innobase/os/os0event.cc:166

#2  0x000055e4d0994b49 in os_event::wait_low (this=0x55e4d36213a0, reset_sig_count=3533) at /data/src/10.3/storage/innobase/os/os0event.cc:336

#3  0x000055e4d0994eef in os_event_wait_low (event=0x55e4d36213a0, reset_sig_count=3533) at /data/src/10.3/storage/innobase/os/os0event.cc:535

#4  0x000055e4d0aa5b08 in sync_array_wait_event (arr=0x55e4d2975530, cell=@0x7ff9e5c0a960: 0x55e4d2975740) at /data/src/10.3/storage/innobase/sync/sync0arr.cc:475

#5  0x000055e4d08e5862 in TTASEventMutex<GenericPolicy>::enter (this=0x55e4d3621290, max_spins=60, max_delay=6, filename=0x55e4d0ffd110 "/data/src/10.3/storage/innobase/handler/ha_innodb.cc", line=5937) at /data/src/10.3/storage/innobase/include/ib0mutex.h:516

#6  0x000055e4d08e3e4b in PolicyMutex<TTASEventMutex<GenericPolicy> >::enter (this=0x55e4d3621290, n_spins=30, n_delay=6, name=0x55e4d0ffd110 "/data/src/10.3/storage/innobase/handler/ha_innodb.cc", line=5937) at /data/src/10.3/storage/innobase/include/ib0mutex.h:635

#7  0x000055e4d08bebfa in innobase_build_index_translation (table=0x7ff97411c040, ib_table=0x7ff9740c2fd8, share=0x7ff9740fb610) at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:5937

#8  0x000055e4d08bfc94 in ha_innobase::open (this=0x7ff9740ba078, name=0x7ff9740cc508 "./test/t17") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:6388

#9  0x000055e4d05962fa in handler::ha_open (this=0x7ff9740ba078, table_arg=0x7ff97411c040, name=0x7ff9740cc508 "./test/t17", mode=2, test_if_locked=18, mem_root=0x0) at /data/src/10.3/sql/handler.cc:2515

#10 0x000055e4d03d1d0e in open_table_from_share (thd=0x7ff974000b00, share=0x7ff9740cbfe8, alias=0x7ff974029e78 "t17", db_stat=33, prgflag=8, ha_open_flags=18, outparam=0x7ff97411c040, is_create_table=false) at /data/src/10.3/sql/table.cc:3339

#11 0x000055e4d024621b in open_table (thd=0x7ff974000b00, table_list=0x7ff974029e80, ot_ctx=0x7ff9e5c0b400) at /data/src/10.3/sql/sql_base.cc:1907

#12 0x000055e4d039add2 in mysql_inplace_alter_table (thd=0x7ff974000b00, table_list=0x7ff974029e80, table=0x0, altered_table=0x7ff97411c040, ha_alter_info=0x7ff9e5c0b570, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7ff9e5c0b5e0, alter_ctx=0x7ff9e5c0c1a0) at /data/src/10.3/sql/sql_table.cc:7293

#13 0x000055e4d039ff7c in mysql_alter_table (thd=0x7ff974000b00, new_db=0x7ff97402a490 "test", new_name=0x0, create_info=0x7ff9e5c0cdb0, table_list=0x7ff974029e80, alter_info=0x7ff9e5c0cd00, order_num=0, order=0x0, ignore=false) at /data/src/10.3/sql/sql_table.cc:9237

#14 0x000055e4d0420023 in Sql_cmd_alter_table::execute (this=0x7ff97402a4a0, thd=0x7ff974000b00) at /data/src/10.3/sql/sql_alter.cc:331

#15 0x000055e4d02d14da in mysql_execute_command (thd=0x7ff974000b00) at /data/src/10.3/sql/sql_parse.cc:6245

#16 0x000055e4d02d5ede in mysql_parse (thd=0x7ff974000b00, rawbuf=0x7ff974029d48 "ALTER TABLE t17 FORCE, ALGORITHM=INPLACE /* QNO 11620 CON_ID 18 */", length=66, parser_state=0x7ff9e5c0e660, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7959

#17 0x000055e4d02c381a in dispatch_command (command=COM_QUERY, thd=0x7ff974000b00, packet=0x7ff97400b041 "ALTER TABLE t17 FORCE, ALGORITHM=INPLACE /* QNO 11620 CON_ID 18 */", packet_length=66, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1828

#18 0x000055e4d02c223b in do_command (thd=0x7ff974000b00) at /data/src/10.3/sql/sql_parse.cc:1370

#19 0x000055e4d041ab9c in do_handle_one_connection (connect=0x55e4d3370e60) at /data/src/10.3/sql/sql_connect.cc:1420

#20 0x000055e4d041a929 in handle_one_connection (arg=0x55e4d3370e60) at /data/src/10.3/sql/sql_connect.cc:1326

#21 0x00007ff9ff17d494 in start_thread (arg=0x7ff9e5c0f700) at pthread_create.c:333

#22 0x00007ff9fd56393f in clone () from /lib/x86_64-linux-gnu/libc.so.6

All threads' stack trace from the hang is attached as hang_threads.

It happened upon running a huge (automatically generated) MTR test, on 2nd repetition. The test is attached.

perl ./mtr bug.latch1 --default-server --mysqld=--sql-mode= --mysqld=--max-statement-time=30 --mysqld=--innodb_stats_persistent=0 --mem --testcase-timeout=300 --mysqld=--lock-wait-timeout=5 --mysqld=--innodb-lock-wait-timeout=3 --repeat=5

Not easily reproducible.

[MDEV-14625] [Draft] Assertion `!rw_lock_own(btr_get_search_latch(index), RW_LOCK_X)' failed in btr_search_info_update Created: 2017-12-11 Updated: 2018-02-21 Resolved: 2018-02-21
Status:	Closed
Project:	MariaDB Server
Component/s:	Storage Engine - InnoDB
Affects Version/s:	10.2.5, 10.3.0
Fix Version/s:	10.3.4, 10.2.13

[MDEV-14625] [Draft] Assertion `!rw_lock_own(btr_get_search_latch(index), RW_LOCK_X)' failed in btr_search_info_update Created: 2017-12-11 Updated: 2018-02-21 Resolved: 2018-02-21