Crash with PXC debug build

Bug #1205529 reported by Raghavendra D Prabhu
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL Server
Unknown
Unknown
MySQL patches by Codership
In Progress
Low
Seppo Jaakola
Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC
Status tracked in 5.6
5.5
Fix Committed
High
Unassigned
5.6
Fix Committed
High
Unassigned

Bug Description

Log:
==============================
InnoDB: DEBUG: update_statistics for sakila/film.
 mysqld: /media/Tintin/Work/code/percona-xtradb-cluster/trunk/Percona-Server/sql/handler.h:1035: bool Ha_trx_info::is_trx_read_write() const: Assertion `is_started()' failed.
 23:07:25 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=3
 max_threads=153
 thread_count=3
 connection_count=3
 It is possible that mysqld could use up to
 key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 343052 K bytes of memory
 Hope that's ok; if not, decrease some variables in the equation.

 Thread pointer: 0x23c03b0
 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 = 7f00241b8e68 thread_stack 0x40000
 /pxc/bin//mysqld(my_print_stacktrace+0x2c)[0x810cda]
 /pxc/bin//mysqld(handle_fatal_signal+0x30f)[0x6d0a0b]
 /usr/lib/libpthread.so.0(+0xf0e0)[0x7f00371780e0]
 /usr/lib/libc.so.6(gsignal+0x39)[0x7f00359271c9]
 /usr/lib/libc.so.6(abort+0x148)[0x7f00359285c8]
 /usr/lib/libc.so.6(+0x2e356)[0x7f0035920356]
 /usr/lib/libc.so.6(+0x2e402)[0x7f0035920402]
 /pxc/bin//mysqld(_Z28stmt_has_updated_trans_tablePK3THD+0x47)[0x7656a0]
 /pxc/bin//mysqld(_ZN15Query_log_eventC2EP3THDPKcmbbbi+0x462)[0x77dd60]
 /pxc/bin//mysqld[0x771c06]
 /pxc/bin//mysqld[0x6d2846]
 /pxc/bin//mysqld(_Z15ha_commit_transP3THDb+0x607)[0x6d46f7]
 /pxc/bin//mysqld(_Z17trans_commit_stmtP3THD+0x76)[0x6663d8]
 /pxc/bin//mysqld(_Z21mysql_execute_commandP3THD+0x7a43)[0x5a59fb]
 /pxc/bin//mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x20a)[0x5a6bb1]
 /pxc/bin//mysqld[0x5a7823]
 /pxc/bin//mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xa62)[0x5a87f9]
 /pxc/bin//mysqld(_Z10do_commandP3THD+0x6c0)[0x5aa704]
 /pxc/bin//mysqld(_Z24do_handle_one_connectionP3THD+0x143)[0x6573ca]
 /pxc/bin//mysqld(handle_one_connection+0x49)[0x6575fe]
 /usr/lib/libpthread.so.0(+0x7dd2)[0x7f0037170dd2]
 /usr/lib/libc.so.6(clone+0x6d)[0x7f00359d7cdd]

 Trying to get some variables.
 Some pointers may be invalid and cause the dump to abort.
 Query (7f00001e9f30): INSERT INTO film VALUES (1,'ACADEMY DINOSAUR','A Epic Drama of a Feminist And a Mad Scientist who must Battle a Teacher in The Canadian Rockies',2006,1,NULL,6,'0.99',86,'20.99','PG','Deleted Scenes,Behind the Scenes','2006-02-15 05:03:42'),(2,'ACE GOLDFINGER','A Astounding Epistle of a Database Administrator And a Explorer who must Find a Car in Ancient China',2006,1,NULL,3,'4.99',48,'12.99','G','Tr ailers,Deleted Scenes','2006-02-15 05:03:42'),(3,'ADAPTATION HOLES','A Astounding Reflection of a Lumberjack And a Car who must Sink a Lumberjack in A Baloon Factory',2006,1,NULL,7,'2.99',50,'18.99','NC-17','Trai lers,Deleted Scenes','2006-02-15 05:03:42'),(4,'AFFAIR PREJUDICE','A Fanciful Documentary of a Frisbee And a Lumberjack who must Chase a Monkey in A Shark Tank',2006,1,NULL,5,'2.99',117,'26.99','G','Commentaries, Behind the Scenes','2006-02-15 05:03:42'),(5,'AFRICAN EGG','A Fast-Paced Documentary of a Pastry Chef And a Dentist who must Pursue a Forensic Psychologist in The Gulf of Mexico',2006,1,NULL,6,'2.99
 Connection ID (thread ID): 6
 Status: NOT_KILLED

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

Backtrace:

0x7656a0 stmt_has_updated_trans_table(THD const*) + 71
0x77dd60 Query_log_event::Query_log_event(THD*, char const*, unsigned long, bool, bool, bool, int) + 1122
0x771c06 binlog_commit(handlerton*, THD*, bool) + 499
0x6d2846 commit_one_phase_low(THD*, bool, THD_TRANS*, bool) + 313
0x6d46f7 ha_commit_trans(THD*, bool) + 1543
0x6663d8 trans_commit_stmt(THD*) + 118
0x5a59fb mysql_execute_command(THD*) + 31299
0x5a6bb1 mysql_parse(THD*, char*, unsigned int, Parser_state*) + 522
0x5a7823 wsrep_mysql_parse(THD*, char*, unsigned int, Parser_state*) + 278
0x5a87f9 dispatch_command(enum_server_command, THD*, char*, unsigned int) + 2658
0x5aa704 do_command(THD*) + 1728
0x6573ca do_handle_one_connection(THD*) + 323
0x6575fe handle_one_connection + 73
0x7f0037170dd2 _end + 905601290
0x7f00359d7cdd _end + 880857109

Full log:

https://gist.github.com/226ac21054cb48bba025

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

I am able to repeat this with codership 5.5.32 as well. Adding that as well.

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

This is repeatable with xtrabackup test suite. (from lp:percona-xtrabackup)

./run.sh -g -c xtradb55 -d /mysql -t t/xb_galera_sst.sh

should do.

(run.sh is part of that tree, /mysql is the mysql basedir)

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

From preliminary analysis, it looks like register_ha/register_ha_trans may be missing there.

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

To reproduce this, you may not need the test suite. Just start the debug build (UNIV_DEBUG) of server and try a load database (sakila in this case).

Revision history for this message
Seppo Jaakola (seppo-jaakola) wrote :

This can be reproduced simply by starting one node and loading sakila-data.sql

mysql ... < inc/sakila-db/sakila-data.sql

There is one offending insert statement.

Changed in codership-mysql:
assignee: nobody → Seppo Jaakola (seppo-jaakola)
status: New → In Progress
Revision history for this message
Seppo Jaakola (seppo-jaakola) wrote :

Only one row insert to film table in sakila-data.sql can cause this issue. Problem happens during processing of ins_film trigger. If the trigger execution fails for duplicate key, then the parent transaction will hit this debug level assert later on.

Revision history for this message
Seppo Jaakola (seppo-jaakola) wrote :

The anatomy of the issue is as follows:
* table 'film' is InnoDB table and has a trigger, which inserts rows in table 'film_text', which is MyISAM table
* INSERT in film succeeds but the trigger operation fails for duplicate key error
* the statement transaction runs rollback in MyISAM, InnoDB and binlog handlers
* rollback in binlog fails for debug level assert, and this is because binlog handler info is not in the first position in transaction's handler list as wsrep patch has added wsrep handler in the head of the list.

Changed in codership-mysql:
importance: Undecided → Low
Revision history for this message
Raghavendra D Prabhu (raghavendra-prabhu) wrote :

Issue is still reproducible.

tags: added: myisam
tags: added: upstream
Revision history for this message
Miguel Angel Nieto (miguelangelnieto) wrote :

Cannot reproduce in latest 5.5 and 5.6. Using UNIV_DEBUG in both.

141130 6:22:26 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!

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/PXC-971

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

Other bug subscribers

Remote bug watches

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