5.6 server hangs during combinations test #221
Description
Jenkins log:
#2015-10-29T00:09:57 [16633] [1] runall-new.pl exited with exit status STATUS_OK(0), see /var/lib/jenkins/workspace/combinations/workdir/trial44.log
#2015-10-29T00:09:57 [16633] [1] Running combination 45/64
#2015-10-29T00:09:57 [16633] [1] bash -c "set -o pipefail; perl /var/lib/jenkins/cache/randgen_gc/runall-new.pl --queries=10000 --mysqld=--query-cache-type=1 --mysqld=--query-cache-size=1M --seed=random --short_column_names --mysqld=--skip-performance-schema --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --grammar=conf/galera/galera_stress-56.yy --gendata=conf/galera/galera_stress-56.zz --threads=10 --reporter=Shutdown,Backtrace,ErrorLog,ErrorLogAlarm,Deadlock --mysqld=--innodb_flush_method=O_DIRECT --mysqld=--innodb_change_buffering=none --mysqld=--innodb_lock_wait_timeout=50 --mysqld=--lock_wait_timeout=50 --mysqld=--wsrep_retry_autocommit=0 --mysqld=--wsrep_slave_threads=4 --mysqld=--wsrep_causal_reads=ON --mysqld=--innodb_flush_log_at_trx_commit=0 --mysqld=--transaction-isolation=READ-COMMITTED --mysqld=--binlog-format=ROW --mysqld=--binlog-row-image=full --rows=1000 --galera=ms --mysqld=--wsrep-provider=/var/lib/jenkins/workspace/combinations/galera/libgalera_smm.so --mtr-build-thread=400 --mask=48010 --duration=60 --basedir1=/var/lib/jenkins/workspace/combinations/mysql-wsrep --gendata=./conf/galera/galera_stress-56.zz --grammar=./conf/galera/galera_stress-56.yy --vardir1=/var/lib/jenkins/workspace/combinations/workdir/current1_1 2>&1 | tee /var/lib/jenkins/workspace/combinations/workdir/trial45.log"
#2015-10-29T00:09:58 [28788] Copyright (c) 2010,2011 Oracle and/or its affiliates. All rights reserved. Use is subject to license terms.
#2015-10-29T00:09:58 [28788] Please see http://forge.mysql.com/wiki/Category:RandomQueryGenerator for more information on this test framework.
#2015-10-29T00:09:58 [28788] Starting
#2015-10-29T00:09:58 [28788] # /var/lib/jenkins/cache/randgen_gc/runall-new.pl \
#2015-10-29T00:09:58 [28788] # --queries=10000 \
#2015-10-29T00:09:58 [28788] # --mysqld=--query-cache-type=1 \
#2015-10-29T00:09:58 [28788] # --mysqld=--query-cache-size=1M \
#2015-10-29T00:09:58 [28788] # --seed=random \
#2015-10-29T00:09:58 [28788] # --short_column_names \
#2015-10-29T00:09:58 [28788] # --mysqld=--skip-performance-schema \
#2015-10-29T00:09:58 [28788] # --mysqld=--log-output=none \
#2015-10-29T00:09:58 [28788] # --mysqld=--sql_mode=ONLY_FULL_GROUP_BY \
#2015-10-29T00:09:58 [28788] # --grammar=conf/galera/galera_stress-56.yy \
#2015-10-29T00:09:58 [28788] # --gendata=conf/galera/galera_stress-56.zz \
#2015-10-29T00:09:58 [28788] # --threads=10 \
#2015-10-29T00:09:58 [28788] # --reporter=Shutdown,Backtrace,ErrorLog,ErrorLogAlarm,Deadlock \
#2015-10-29T00:09:58 [28788] # --mysqld=--innodb_flush_method=O_DIRECT \
#2015-10-29T00:09:58 [28788] # --mysqld=--innodb_change_buffering=none \
#2015-10-29T00:09:58 [28788] # --mysqld=--innodb_lock_wait_timeout=50 \
#2015-10-29T00:09:58 [28788] # --mysqld=--lock_wait_timeout=50 \
#2015-10-29T00:09:58 [28788] # --mysqld=--wsrep_retry_autocommit=0 \
#2015-10-29T00:09:58 [28788] # --mysqld=--wsrep_slave_threads=4 \
#2015-10-29T00:09:58 [28788] # --mysqld=--wsrep_causal_reads=ON \
#2015-10-29T00:09:58 [28788] # --mysqld=--innodb_flush_log_at_trx_commit=0 \
#2015-10-29T00:09:58 [28788] # --mysqld=--transaction-isolation=READ-COMMITTED \
#2015-10-29T00:09:58 [28788] # --mysqld=--binlog-format=ROW \
#2015-10-29T00:09:58 [28788] # --mysqld=--binlog-row-image=full \
#2015-10-29T00:09:58 [28788] # --rows=1000 \
#2015-10-29T00:09:58 [28788] # --galera=ms \
#2015-10-29T00:09:58 [28788] # --mysqld=--wsrep-provider=/var/lib/jenkins/workspace/combinations/galera/libgalera_smm.so \
#2015-10-29T00:09:58 [28788] # --mtr-build-thread=400 \
#2015-10-29T00:09:58 [28788] # --mask=48010 \
#2015-10-29T00:09:58 [28788] # --duration=60 \
#2015-10-29T00:09:58 [28788] # --basedir1=/var/lib/jenkins/workspace/combinations/mysql-wsrep \
#2015-10-29T00:09:58 [28788] # --gendata=./conf/galera/galera_stress-56.zz \
#2015-10-29T00:09:58 [28788] # --grammar=./conf/galera/galera_stress-56.yy \
#2015-10-29T00:09:58 [28788] # --vardir1=/var/lib/jenkins/workspace/combinations/workdir/current1_1
#2015-10-29T00:09:58 [28788] master_port : 14000 slave_port : 14002 ports : 14000 14002 MTR_BUILD_THREAD : 400
#2015-10-29T00:09:58 [28788] /var/lib/jenkins/cache/randgen_gc Revno: 932
#2015-10-29T00:09:58 [28788] /var/lib/jenkins/cache/randgen_gc Revision-Id: philip.stoev@galeracluster.com-20141201101049-f2p9aoulf4awept5
#2015-10-29T00:09:58 [28788] /var/lib/jenkins/workspace/combinations/mysql-wsrep does not look like a bzr branch, cannot get revision info.
#2015-10-29T00:09:58 [28788] Found source directory at /var/lib/jenkins/workspace/combinations/mysql-wsrep
#2015-10-29T00:09:59 [28788] Creating MySQL 5.6.27 database at /var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/data
#2015-10-29T00:10:04 [28788] Found source directory at /var/lib/jenkins/workspace/combinations/mysql-wsrep
#2015-10-29T00:10:04 [28788] Creating MySQL 5.6.27 database at /var/lib/jenkins/workspace/combinations/workdir/current1_1/node1/data
#2015-10-29T00:10:11 [28788] MySQL Version:5.6.27
#2015-10-29T00:10:11 [28788] Binary: /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/mysqld
#2015-10-29T00:10:11 [28788] Type: Debug
#2015-10-29T00:10:11 [28788] Datadir: /var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/data
#2015-10-29T00:10:11 [28788] Tmpdir: /var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/tmp
#2015-10-29T00:10:11 [28788] Corefile: /var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/data/core.
#2015-10-29T00:10:11 [28788] Starting MySQL 5.6.27: "/var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/mysqld" "--no-defaults" "--skip-grant-tables" "--basedir=/var/lib/jenkins/workspace/combinations/mysql-wsrep" "--datadir=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/data" "--lc-messages-dir=/var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/share" "--character-sets-dir=/var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/share/charsets" "--tmpdir=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/tmp" "--core-file" "--max-allowed-packet=128Mb" "--port=14000" "--socket=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/mysql.sock" "--pid-file=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/mysql.pid" "--general-log" "--general-log-file=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/mysql.log" --wsrep_sst_method=rsync --innodb_autoinc_lock_mode=2 --default-storage-engine=InnoDB --innodb_locks_unsafe_for_binlog=1 --binlog-format=row --wsrep_node_incoming_address=127.0.0.1 --wsrep_node_address=127.0.0.1 --wsrep_cluster_address='gcomm://?gmcast.listen_addr=tcp://127.0.0.1:4819' --wsrep_sst_receive_address=127.0.0.1:4822 --query-cache-type=1 --query-cache-size=1M --skip-performance-schema --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --innodb_flush_method=O_DIRECT --innodb_change_buffering=none --innodb_lock_wait_timeout=50 --lock_wait_timeout=50 --wsrep_retry_autocommit=0 --wsrep_slave_threads=4 --wsrep_causal_reads=ON --innodb_flush_log_at_trx_commit=0 --transaction-isolation=READ-COMMITTED --binlog-format=ROW --binlog-row-image=full --wsrep-provider=/var/lib/jenkins/workspace/combinations/galera/libgalera_smm.so
#2015-10-29T00:10:13 [28788] Cluster size after starting node 0: 1
#2015-10-29T00:10:13 [28788] MySQL Version:5.6.27
#2015-10-29T00:10:13 [28788] Binary: /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/mysqld
#2015-10-29T00:10:13 [28788] Type: Debug
#2015-10-29T00:10:13 [28788] Datadir: /var/lib/jenkins/workspace/combinations/workdir/current1_1/node1/data
#2015-10-29T00:10:13 [28788] Tmpdir: /var/lib/jenkins/workspace/combinations/workdir/current1_1/node1/tmp
#2015-10-29T00:10:13 [28788] Corefile: /var/lib/jenkins/workspace/combinations/workdir/current1_1/node1/data/core.
#2015-10-29T00:10:13 [28788] Starting MySQL 5.6.27: "/var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/mysqld" "--no-defaults" "--skip-grant-tables" "--basedir=/var/lib/jenkins/workspace/combinations/mysql-wsrep" "--datadir=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node1/data" "--lc-messages-dir=/var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/share" "--character-sets-dir=/var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/share/charsets" "--tmpdir=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node1/tmp" "--core-file" "--max-allowed-packet=128Mb" "--port=14001" "--socket=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node1/mysql.sock" "--pid-file=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node1/mysql.pid" "--general-log" "--general-log-file=/var/lib/jenkins/workspace/combinations/workdir/current1_1/node1/mysql.log" --wsrep_sst_method=rsync --innodb_autoinc_lock_mode=2 --default-storage-engine=InnoDB --innodb_locks_unsafe_for_binlog=1 --binlog-format=row --wsrep_node_incoming_address=127.0.0.1 --wsrep_node_address=127.0.0.1 --wsrep_cluster_address='gcomm://127.0.0.1:4819?gmcast.listen_addr=tcp://127.0.0.1:4820' --wsrep_sst_receive_address=127.0.0.1:4823 --query-cache-type=1 --query-cache-size=1M --skip-performance-schema --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --innodb_flush_method=O_DIRECT --innodb_change_buffering=none --innodb_lock_wait_timeout=50 --lock_wait_timeout=50 --wsrep_retry_autocommit=0 --wsrep_slave_threads=4 --wsrep_causal_reads=ON --innodb_flush_log_at_trx_commit=0 --transaction-isolation=READ-COMMITTED --binlog-format=ROW --binlog-row-image=full --wsrep-provider=/var/lib/jenkins/workspace/combinations/galera/libgalera_smm.so
#2015-10-29T00:10:19 [28788] Cluster size after starting node 1: 2
#2015-10-29T00:10:19 [28788] Converting --seed=random to --seed=31170
#2015-10-29T00:10:19 [28788] -------------------------------
#2015-10-29T00:10:19 [28788] Configuration
#2015-10-29T00:10:19 [28788] debug_server => ['', '']
#2015-10-29T00:10:19 [28788] dsn => ['dbi:mysql:host=127.0.0.1:port=14000:user=root:database=test']
#2015-10-29T00:10:19 [28788] duration => 60
#2015-10-29T00:10:19 [28788] gendata => ./conf/galera/galera_stress-56.zz
#2015-10-29T00:10:19 [28788] generator => FromGrammar
#2015-10-29T00:10:19 [28788] grammar => ./conf/galera/galera_stress-56.yy
#2015-10-29T00:10:19 [28788] mask => 48010
#2015-10-29T00:10:19 [28788] queries => 10000
#2015-10-29T00:10:19 [28788] reporters => ['Shutdown', 'Backtrace', 'ErrorLog', 'ErrorLogAlarm', 'Deadlock']
#2015-10-29T00:10:19 [28788] rows => 1000
#2015-10-29T00:10:19 [28788] seed => 31170
#2015-10-29T00:10:19 [28788] servers => ['DBServer::MySQL::MySQLd=ARRAY(0x16fe960)', 'DBServer::MySQL::MySQLd=ARRAY(0x983cf0)']
#2015-10-29T00:10:19 [28788] short_column_names => 1
#2015-10-29T00:10:19 [28788] threads => 10
#2015-10-29T00:10:19 [28788] views => ['', '']
#2015-10-29T00:10:19 [28788] # Creating MySQL table: test.table1000_innodb_int; engine: innodb; rows: 1000 .
#2015-10-29T00:10:19 [28788] # Creating MySQL table: test.table1000_innodb_int_autoinc; engine: innodb; rows: 1000 .
#2015-10-29T00:10:20 [28788] Reporters: Shutdown, Backtrace, ErrorLog, ErrorLogAlarm, Deadlock
#2015-10-29T00:10:21 [28788] Validators: ErrorMessageCorruption
#2015-10-29T00:10:21 [28788] Caching schema metadata for dbi:mysql:host=127.0.0.1:port=14000:user=root:database=test
#2015-10-29T00:10:21 [28788] Starting 10 processes, 10000 queries each, duration 60 seconds.
#2015-10-29T00:10:21 [28788] GenTest::ErrorFilter(29359) started
#2015-10-29T00:10:21 [29361] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:21 [29362] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:21 [29364] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:21 [29366] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:21 [29359] Query: INSERT INTO `table1000_innodb_int` ( `pk` , `c0` ) VALUES ( 'g' , 52 ) , ( 185 , 'j' ) failed: 1062 Duplicate entry '%s' for key '%s'. Further errors of this kind will be suppressed.
#2015-10-29T00:10:21 [29368] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:21 [29359] Query: INSERT INTO `table1000_innodb_int_autoinc` ( `c0` , `c0` ) VALUES ( 'v' , 8 ) , ( 'b' , 9 ) failed: 1110 Column '%s' specified twice. Further errors of this kind will be suppressed.
#2015-10-29T00:10:21 [29370] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:22 [29372] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:22 [29374] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:22 [29376] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:22 [29378] Loading Validator GenTest::Validator::ErrorMessageCorruption.
#2015-10-29T00:10:22 [29360] Started periodic reporting process...
#2015-10-29T00:10:22 [29360] ErrorLogAlarm Reporter will monitor the log file /var/lib/jenkins/workspace/combinations/workdir/current1_1/node0/data/../mysql.err
#2015-10-29T00:12:22 [29360] Actual test duration (122 seconds) is more than 2 times the desired duration (60 seconds)
Processlist:
mysql> mysql> show processlist;
+----+-------------+-----------+------+---------+-------+-------------------------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+-------------+-----------+------+---------+-------+-------------------------------+------------------------------------------------------------------------------------------------------+
| 1 | system user | | NULL | Sleep | 35022 | wsrep aborter idle | NULL |
| 2 | system user | | NULL | Sleep | 35022 | NULL | NULL |
| 3 | system user | | NULL | Sleep | 35021 | NULL | NULL |
| 4 | system user | | NULL | Sleep | 35021 | NULL | NULL |
| 5 | system user | | NULL | Sleep | 35021 | NULL | NULL |
| 14 | root | localhost | test | Query | 34982 | storing result in query cache | SELECT X . `c3`, X.`c3` FROM `table1000_innodb_int_autoinc` AS X LEFT JOIN `table1000_innodb_int_aut |
| 15 | root | localhost | test | Query | 34982 | Sending data | SELECT X.`c3` = X.`c3` FROM `table1000_innodb_int` AS X WHERE X . `c1` < 0 ORDER BY X . `c3` LIMIT 7 |
| 16 | root | localhost | test | Query | 34982 | storing result in query cache | SELECT * FROM `table1000_innodb_int_autoinc` AS X WHERE X . `c3` BETWEEN 196 AND 695861248 ORDER BY |
| 17 | root | localhost | test | Query | 34982 | storing result in query cache | SELECT X. `c0` IS NOT NULL FROM `table1000_innodb_int_autoinc` AS X WHERE X . `c3` BETWEEN 253 AND 3 |
| 18 | root | localhost | test | Query | 34982 | Sending data | SELECT X. `c0` DIV X. `c2` FROM `table1000_innodb_int` AS X LEFT JOIN `table1000_innodb_int_autoinc` |
| 19 | root | localhost | test | Query | 34982 | storing result in query cache | SELECT X . `c3` FROM `table1000_innodb_int` AS X LEFT JOIN `table1000_innodb_int_autoinc` AS Y USING |
| 20 | root | localhost | test | Query | 34982 | storing result in query cache | SELECT X . `pk`, X.`c3` FROM `table1000_innodb_int_autoinc` AS X WHERE X . `c3` IN ( 8 , 42 , 'z' , |
| 21 | root | localhost | test | Query | 34982 | Creating sort index | REPLACE INTO `table1000_innodb_int_autoinc` ( `c0` ) SELECT `c3` FROM `table1000_innodb_int` AS X O |
| 22 | root | localhost | test | Query | 34982 | storing result in query cache | SELECT X . `c3` FROM `table1000_innodb_int_autoinc` AS X LEFT JOIN `table1000_innodb_int_autoinc` AS |
| 23 | root | localhost | test | Query | 34982 | storing result in query cache | SELECT X . `c3` FROM `table1000_innodb_int` AS X LEFT JOIN `table1000_innodb_int` AS Y USING ( `c3` |
| 37 | root | localhost | NULL | Query | 0 | init | show processlist |
+----+-------------+-----------+------+---------+-------+-------------------------------+------------------------------------------------------------------------------------------------------+
Many threads were hanging in mutex lock, for example:
Thread 4 (Thread 0x7f3f601b5700 (LWP 29377)):
#0 __lll_lock_wait ()
at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1 0x00007f3f8fab468d in _L_lock_1082 ()
from /lib/x86_64-linux-gnu/libpthread.so.0
#2 0x00007f3f8fab4607 in __GI___pthread_mutex_lock (mutex=0x320c6e0)
at ../nptl/pthread_mutex_lock.c:134
#3 0x0000000000bfd4f4 in os_fast_mutex_lock_func (fast_mutex=0x320c6e0)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/os/os0sync.cc:855
#4 0x0000000000bfc8ae in pfs_os_fast_mutex_lock (fast_mutex=0x320c6e0,
file_name=0x10f2fe8 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/os/os0sync.cc", line=761)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/include/os0sync.ic:128
#5 0x0000000000bfd294 in os_mutex_enter (mutex=0x3217210)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/os/os0sync.cc:761
#6 0x0000000000cc45a9 in sync_array_enter (arr=0x31530d0)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0arr.cc:192
#7 0x0000000000cc487c in sync_array_reserve_cell (arr=0x31530d0,
object=0x1860c20 <sync_thread_mutex>, type=354,
file=0x1123fc0 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0sync.cc", line=1088, index=0x7f3f601b1560)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0arr.cc:327
#8 0x0000000000cc85fe in sync_array_get_and_reserve_cell (
object=0x1860c20 <sync_thread_mutex>, type=354,
file=0x1123fc0 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0sync.cc", line=1088, index=0x7f3f601b1560)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/include/sync0arr.ic:54
#9 0x0000000000cc915f in mutex_spin_wait (
mutex=0x1860c20 <sync_thread_mutex>,
file_name=0x1123fc0 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0sync.cc", line=1088)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0sync.cc:542
#10 0x0000000000cc883b in mutex_enter_func (
mutex=0x1860c20 <sync_thread_mutex>,
file_name=0x1123fc0 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0sync.cc", line=1088)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/include/sync0sync.ic:220
#11 0x0000000000cc88e6 in pfs_mutex_enter_func (
mutex=0x1860c20 <sync_thread_mutex>,
file_name=0x1123fc0 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0sync.cc", line=1088)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/include/sync0sync.ic:252
#12 0x0000000000cc9baf in sync_thread_add_level (latch=0x7f3f63a9fd70,
level=146, relock=0)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0sync.cc:1088
#13 0x0000000000cc92d1 in mutex_set_debug_info (mutex=0x7f3f63a9fd70,
file_name=0x113c8b0 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/buf/buf0buf.cc", line=3169)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/sync/sync0sync.cc:615
#14 0x0000000000d3a455 in mutex_enter_func (mutex=0x7f3f63a9fd70,
file_name=0x113c8b0 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/buf/buf0buf.cc", line=3169)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/include/sync0sync.ic:215
#15 0x0000000000d3a519 in pfs_mutex_enter_func (mutex=0x7f3f63a9fd70,
file_name=0x113c8b0 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/buf/buf0buf.cc", line=3169)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/include/sync0sync.ic:252
#16 0x0000000000d43b7e in buf_page_optimistic_get (rw_latch=1,
block=0x7f3f63a9fcc0, modify_clock=47,
file=0x1114948 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/row/row0sel.cc", line=3220, mtr=0x7f3f601b1d20)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/buf/buf0buf.cc:3169
#17 0x0000000000d2ee83 in btr_pcur_restore_position_func (latch_mode=1,
cursor=0x7f3f2c076d90,
file=0x1114948 "/var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/row/row0sel.cc", line=3220, mtr=0x7f3f601b1d20)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/btr/btr0pcur.cc:273
#18 0x0000000000c9bb82 in sel_restore_position_for_mysql (
same_user_rec=0x7f3f601b1948, latch_mode=1, pcur=0x7f3f2c076d90,
moves_up=1, mtr=0x7f3f601b1d20)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/row/row0sel.cc:3220
#19 0x0000000000c9f276 in row_search_for_mysql (buf=0x7f3f2c24e3b8 "\343a",
mode=1, prebuilt=0x7f3f2c076d18, match_mode=0, direction=1)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/row/row0sel.cc:5000
#20 0x0000000000b7e313 in ha_innobase::general_fetch (this=0x7f3f2c24e0f0,
buf=0x7f3f2c24e3b8 "\343a", direction=1, match_mode=0)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/handler/ha_innodb.cc:8482
#21 0x0000000000b7e52f in ha_innobase::index_next (this=0x7f3f2c24e0f0,
buf=0x7f3f2c24e3b8 "\343a")
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/storage/innobase/handler/ha_innodb.cc:8544
#22 0x0000000000651254 in handler::ha_index_next (this=0x7f3f2c24e0f0,
buf=0x7f3f2c24e3b8 "\343a")
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/handler.cc:2886
#23 0x00000000007bd355 in join_read_next (info=0x7f3f04068908)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_executor.cc:2550
#24 0x00000000007ba611 in sub_select (join=0x7f3f04065bd0,
join_tab=0x7f3f04068878, end_of_records=false)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_executor.cc:1259
#25 0x00000000007ba02a in do_select (join=0x7f3f04065bd0)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_executor.cc:933
#26 0x00000000007b804a in JOIN::exec (this=0x7f3f04065bd0)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_executor.cc:194
#27 0x000000000081a736 in mysql_execute_select (thd=0x3912660,
select_lex=0x3914d38, free_join=true)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_select.cc:1100
#28 0x000000000081aa10 in mysql_select (thd=0x3912660, tables=0x7f3f04004ed0,
wild_num=0, fields=..., conds=0x7f3f040063d8, order=0x3914f00,
group=0x3914e38, having=0x0, select_options=2147748608,
result=0x7f3f040068d8, unit=0x39146f0, select_lex=0x3914d38)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_select.cc:1221
#29 0x0000000000818984 in handle_select (thd=0x3912660, result=0x7f3f040068d8,
setup_tables_done_option=0)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_select.cc:110
#30 0x00000000007f1e95 in execute_sqlcom_select (thd=0x3912660,
all_tables=0x7f3f04004ed0)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_parse.cc:5641
#31 0x00000000007e94f7 in mysql_execute_command (thd=0x3912660)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_parse.cc:2966
#32 0x00000000007f51f8 in mysql_parse (thd=0x3912660,
rawbuf=0x7f3f04004b10 "SELECT X . `c3` FROM `table1000_innodb_int_autoinc` AS X LEFT JOIN `table1000_innodb_int_autoinc` AS Y USING ( `c1` ) WHERE X . `c3` BETWEEN 3 AND 7 ORDER BY X . `c3` LIMIT 8", length=174,
parser_state=0x7f3f601b4290)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_parse.cc:7040
#33 0x00000000007f4720 in wsrep_mysql_parse (thd=0x3912660,
rawbuf=0x7f3f04004b10 "SELECT X . `c3` FROM `table1000_innodb_int_autoinc` AS X LEFT JOIN `table1000_innodb_int_autoinc` AS Y USING ( `c1` ) WHERE X . `c3` BETWEEN 3 AND 7 ORDER BY X . `c3` LIMIT 8", length=174,
parser_state=0x7f3f601b4290)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_parse.cc:6788
#34 0x00000000007e6151 in dispatch_command (command=COM_QUERY, thd=0x3912660,
packet=0x395db61 "", packet_length=174)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_parse.cc:1552
#35 0x00000000007e4bae in do_command (thd=0x3912660)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_parse.cc:1125
#36 0x00000000007accae in do_handle_one_connection (thd_arg=0x3912660)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_connect.cc:1007
#37 0x00000000007ac7d2 in handle_one_connection (arg=0x3912660)
at /var/lib/jenkins/workspace/combinations/mysql-wsrep/sql/sql_connect.cc:916
#38 0x00007f3f8fab2182 in start_thread (arg=0x7f3f601b5700)
at pthread_create.c:312
#39 0x00007f3f8efbf47d in clone ()
at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
Full backraces:
gdb.txt
TODO: Add InnoDB status if this reproduces.
EDIT: The hang reproduces also with regression test against lp:861212, getting InnoDB status not possible (show engine innodb status hangs).