abort in ha_partition::init_record_priority_queue | sql/ha_partition.cc:4843: bool ha_partition::init_record_priority_queue(): Assertion `!m_ordered_rec_buffer' failed.

Bug #1204863 reported by Roel Van de Paar
14
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.1
Won't Fix
Undecided
Unassigned
5.5
New
Undecided
Unassigned
5.6
New
High
Unassigned
5.7
New
High
Unassigned

Bug Description

Thread 1 (LWP 2124):
+bt
#0 0x000000340cc0c69c in pthread_kill () from /lib64/libpthread.so.0
#1 0x0000000000686bde in handle_fatal_signal (sig=6) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/signal_handler.cc:251
#2 <signal handler called>
#3 0x000000340c4328a5 in raise () from /lib64/libc.so.6
#4 0x000000340c434085 in abort () from /lib64/libc.so.6
#5 0x000000340c42ba1e in __assert_fail_base () from /lib64/libc.so.6
#6 0x000000340c42bae0 in __assert_fail () from /lib64/libc.so.6
#7 0x0000000000c5a472 in ha_partition::init_record_priority_queue (this=0x7f872c021b00) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/ha_partition.cc:4843
#8 0x0000000000c5a561 in ha_partition::index_init (this=0x7f872c021b00, inx=0, sorted=true) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/ha_partition.cc:4949
#9 0x00000000005b4aee in handler::ha_index_init (this=0x7f872c021b00, idx=0, sorted=true) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/handler.cc:2573
#10 0x00000000008688c4 in QUICK_RANGE_SELECT::reset (this=0x7f872c01fd40) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/opt_range.cc:10369
#11 0x000000000079cb38 in mysql_update (thd=0x1bfcba0, table_list=0x7f872c004e18, fields=..., values=..., conds=0x0, order_num=268435455, order=0x0, limit=18446744073709551615, handle_duplicates=DUP_ERROR, ignore=false, found_return=0x7f8799909038, updated_return=0x7f8799909040) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/sql_update.cc:695
#12 0x00000000007212cb in mysql_execute_command (thd=0x1bfcba0) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/sql_parse.cc:3511
#13 0x0000000000727818 in mysql_parse (thd=0x1bfcba0, rawbuf=0x1bfef68 "\360R7\001", length=<optimized out>, parser_state=<optimized out>) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/sql_parse.cc:6477
#14 0x000000000072871f in dispatch_command (command=COM_QUERY, thd=0x1bfcba0, packet=0x1c00521 " UPDATE table0_key_pk_parts_2_int_autoinc SET `col_int_not_null`=`col_int_not_null`+(@val) WHERE pk=@updpk ", packet_length=107) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/sql_parse.cc:1374
#15 0x0000000000729a47 in do_command (thd=0x1bfcba0) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/sql_parse.cc:1049
#16 0x00000000006ed63f in do_handle_one_connection (thd_arg=<optimized out>) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/sql_connect.cc:1615
#17 0x00000000006ed727 in handle_one_connection (arg=0x1bfcba0) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/sql_connect.cc:1526
#18 0x00000000009dd6c9 in pfs_spawn_thread (arg=0x1aa0270) at /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/storage/perfschema/pfs.cc:1855
#19 0x000000340cc07851 in start_thread () from /lib64/libpthread.so.0
#20 0x000000340c4e890d in clone () from /lib64/libc.so.6

2013-07-20 01:54:35 2045 [Note] /ssd/Percona-Server-5.6.12-rc60.4-405-debug.Linux.x86_64/bin/mysqld: ready for connections.
Version: '5.6.12-rc60.4-debug-log' socket: '/ssd/209184/current1_5/tmp/master.sock' port: 13080 Percona Server with XtraDB (GPL), Release rc60.4, Revision 405-debug
2013-07-20 01:55:43 2045 [ERROR] /ssd/Percona-Server-5.6.12-rc60.4-405-debug.Linux.x86_64/bin/mysqld: Lock wait timeout exceeded; try restarting transaction
2013-07-20 01:55:43 2045 [ERROR] /ssd/Percona-Server-5.6.12-rc60.4-405-debug.Linux.x86_64/bin/mysqld: Sort aborted: Lock wait timeout exceeded; try restarting transaction
2013-07-20 01:55:44 2045 [ERROR] /ssd/Percona-Server-5.6.12-rc60.4-405-debug.Linux.x86_64/bin/mysqld: Sort aborted: Table definition has changed, please retry transaction
2013-07-20 01:55:44 2045 [ERROR] /ssd/Percona-Server-5.6.12-rc60.4-405-debug.Linux.x86_64/bin/mysqld: Lock wait timeout exceeded; try restarting transaction
2013-07-20 01:55:44 2045 [ERROR] /ssd/Percona-Server-5.6.12-rc60.4-405-debug.Linux.x86_64/bin/mysqld: Sort aborted: Lock wait timeout exceeded; try restarting transaction
2013-07-20 01:55:44 2045 [ERROR] /ssd/Percona-Server-5.6.12-rc60.4-405-debug.Linux.x86_64/bin/mysqld: Sort aborted: Table definition has changed, please retry transaction
mysqld: /bzr/5.6_dbg/Percona-Server-5.6.12-rc60.4/sql/ha_partition.cc:4843: bool ha_partition::init_record_priority_queue(): Assertion `!m_ordered_rec_buffer' failed.
22:55:44 UTC - mysqld got signal 6 ;
[...]
Query (7f872c004c50): UPDATE table0_key_pk_parts_2_int_autoinc SET `col_int_not_null`=`col_int_not_null`+(@val) WHERE pk=@updpk

Tags: qa upstream pxc
Revision history for this message
Roel Van de Paar (roel11) wrote :
Revision history for this message
Roel Van de Paar (roel11) wrote :
Revision history for this message
Roel Van de Paar (roel11) wrote :
Revision history for this message
Roel Van de Paar (roel11) wrote :

ps -ef | grep 'cmdrun_461' | grep -v grep | awk '{print $2}' | xargs sudo kill -9
rm -Rf /ssd/209184/cmdrun_461
mkdir /ssd/209184/cmdrun_461
cd /ssd/randgen
bash -c "set -o pipefail; perl /ssd/randgen/runall.pl --queries=100000000 --seed=20639 --duration=300 --querytimeout=60 --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --mysqld=--slow_query_log --mysqld=--userstat --threads=25 --basedir=/ssd/Percona-Server-5.6.12-rc60.4-405-debug.Linux.x86_64 --grammar=/tmp/976291/65.yy --gendata=/ssd/randgen/conf/transactions/combinations.zz --mtr-build-thread=709 --mask=23960 --vardir1=/ssd/209184/cmdrun_461 > /ssd/209184/cmdrun461.log 2>&1"

Revision history for this message
Roel Van de Paar (roel11) wrote :
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

99% upstream.

tags: added: upstream
Revision history for this message
Roel Van de Paar (roel11) wrote :

Laurynas, feel free to remove 56qual tag if this bug is "as good as certain" upstream.

tags: added: 56qual
Revision history for this message
Roel Van de Paar (roel11) wrote :

(Definite upstream bugs do not receive 56qual unless it's qablock or crashes mysqld heaps - which may happen with a less-tested upstream minor version containing a major bug for example)

tags: removed: 56qual
Revision history for this message
Raghavendra D Prabhu (raghavendra-prabhu) wrote :
Download full text (3.9 KiB)

Hitting this while PXC 56 testing with identical stacktrace.

mysqld: /media/Tintin/Work/code/percona-xtradb-cluster/pxc56/Percona-Server/sql/ha_partition.cc:4873: bool ha_partition::init_record_priority_queue(): Assertion `!m_ordered_rec_buffer' failed.
13:51:41 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=20
max_threads=153
thread_count=19
connection_count=19
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 69219 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x2350e10
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 = 7fce695f1ed8 thread_stack 0x40000
/pxc56/bin/mysqld(my_print_stacktrace+0x2c)[0x946df8]
/pxc56/bin/mysqld(handle_fatal_signal+0x304)[0x6da024]
/usr/lib/libpthread.so.0(+0xf870)[0x7fce8d9c8870]
/usr/lib/libc.so.6(gsignal+0x39)[0x7fce8bd563d9]
/usr/lib/libc.so.6(abort+0x148)[0x7fce8bd577d8]
/usr/lib/libc.so.6(+0x2e506)[0x7fce8bd4f506]
/usr/lib/libc.so.6(+0x2e5b2)[0x7fce8bd4f5b2]
/pxc56/bin/mysqld(_ZN12ha_partition26init_record_priority_queueEv+0x59)[0xbcb3fb]
/pxc56/bin/mysqld(_ZN12ha_partition10index_initEjb+0x151)[0xbcb6b5]
/pxc56/bin/mysqld(_ZN7handler13ha_index_initEjb+0xc5)[0x645479]
/pxc56/bin/mysqld(_ZN18QUICK_RANGE_SELECT5resetEv+0xdd)[0x860715]
/pxc56/bin/mysqld[0x843b75]
/pxc56/bin/mysqld(_Z8filesortP3THDP5TABLEP8FilesortbPyS5_+0x74c)[0x844314]
/pxc56/bin/mysqld[0x735639]
/pxc56/bin/mysqld(_ZN13st_join_table10sort_tableEv+0xe0)[0x7357a6]
/pxc56/bin/mysqld(_Z21join_init_read_recordP13st_join_table+0x36)[0x73873e]
/pxc56/bin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x13d)[0x7366ee]
/pxc56/bin/mysqld[0x736e49]
/pxc56/bin/mysqld(_ZN4JOIN4execEv+0x3dd)[0x73743f]
/pxc56/bin/mysqld[0x777fef]
/pxc56/bin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_P10SQL_I_ListI8st_orderESB_S7_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x1cf)[0x780092]
/pxc56/bin/mysqld(_Z13handle_selectP3THDP13select_resultm+0x15f)[0x780203]
/pxc56/bin/mysqld(_Z21mysql_execute_commandP3THD+0x27cf)[0x759695]
/pxc56/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x6ef)[0x75dae8]
/pxc56/bin/mysqld[0x75e134]
/pxc56/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xb27)[0x75f087]
/pxc56/bin/mysqld(_Z10do_commandP3THD+0x50b)[0x7605fa]
/pxc56/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x128)[0x72c563]
/pxc56/bin/mysqld(handle_one_connection+0x20)[0x72c68b]
/usr/lib/libpthread.so.0(+0x80a2)[0x7fce8d9c10a2]
/usr/lib/libc.so.6(clone+0x6d)[0x7fce8b...

Read more...

tags: added: pxc
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

Raghu -

We haven't analyzed this enough to make a useful upstream bug report yet (and the upstream-ness of this bug is not 100% confirmed neither).

Revision history for this message
Raghavendra D Prabhu (raghavendra-prabhu) wrote :

Also, seen here https://bugs.launchpad.net/codership-mysql/+bug/1241704 , further points to this being upstream.

@Roel,

Is this repeatable on vanilla mysql on jenkins? If so, then may be we can report it upstream.

Revision history for this message
Raghavendra D Prabhu (raghavendra-prabhu) wrote :

Still reproduceable on 5.6.19.

tags: added: qablock
Revision history for this message
Roel Van de Paar (roel11) wrote :

Still reproducible on 5.6.20. Adding a full set of files

Revision history for this message
Roel Van de Paar (roel11) wrote :
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

Is "qablock" tag on this bug current?

Revision history for this message
Roel Van de Paar (roel11) wrote :

Given pquery coverage, best answer is "no". Will also check with Ramesh re: PXC.

tags: removed: qablock
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-699

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.