Comment 9 for bug 1088400

Revision history for this message
markus_albe (markus-albe) wrote :

Seems to be affecting 5.6 after all:

# node was doing SST
2016-03-06 13:57:26 16021 [Note] WSREP: cleaning up 6dd9af55 (tcp://192.168.1.33:4567)
2016-03-06 14:38:09 16021 [Note] WSREP: (ddea0af2, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2016-03-06 14:38:09 16021 [Note] WSREP: declaring 56777159 at tcp://192.168.1.33:4567 stable
2016-03-06 14:38:09 16021 [Note] WSREP: Node ddea0af2 state prim
2016-03-06 14:38:09 16021 [Note] WSREP: view(view_id(PRIM,56777159,11) memb {
 56777159,0
 ddea0af2,0
} joined {
} left {
} partitioned {
})
2016-03-06 14:38:09 16021 [Note] WSREP: save pc into disk
2016-03-06 14:38:09 16021 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2016-03-06 14:38:09 16021 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2016-03-06 14:38:10 16021 [Note] WSREP: STATE EXCHANGE: sent state msg: 57105efc-e3db-11e5-9f31-17f87c1a003a
2016-03-06 14:38:10 16021 [Note] WSREP: STATE EXCHANGE: got state msg: 57105efc-e3db-11e5-9f31-17f87c1a003a from 0 (node2)
2016-03-06 14:38:10 16021 [Note] WSREP: STATE EXCHANGE: got state msg: 57105efc-e3db-11e5-9f31-17f87c1a003a from 1 (node1)
2016-03-06 14:38:10 16021 [Note] WSREP: Quorum results:
 version = 3,
 component = PRIMARY,
 conf_id = 7,
 members = 1/2 (joined/total),
 act_id = 25900364,
 last_appl. = 25900279,
 protocols = 0/7/3 (gcs/repl/appl),
 group UUID = 659aca7c-e1d4-11e5-a961-4a178457e29f
2016-03-06 14:38:10 16021 [Note] WSREP: Flow-control interval: [1024, 1024]
2016-03-06 14:38:10 16021 [Note] WSREP: New cluster view: global state: 659aca7c-e1d4-11e5-a961-4a178457e29f:25900364, view# 8: Primary, number of nodes: 2, my index: 1, protocol version 3
2016-03-06 14:38:10 16021 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2016-03-06 14:38:10 16021 [Note] WSREP: REPL Protocols: 7 (3, 2)
2016-03-06 14:38:10 16021 [Note] WSREP: Service thread queue flushed.
2016-03-06 14:38:10 16021 [Note] WSREP: Assign initial position for certification: 25900364, protocol version: 3
2016-03-06 14:38:10 16021 [Note] WSREP: Service thread queue flushed.
2016-03-06 14:38:12 16021 [Note] WSREP: (ddea0af2, 'tcp://0.0.0.0:4567') turning message relay requesting off
2016-03-06 14:38:20 16021 [Note] WSREP: Member 0.0 (node2) requested state transfer from '*any*'. Selected 1.0 (node1)(SYNCED) as donor.
2016-03-06 14:38:20 16021 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 25900366)
2016-03-06 14:38:20 16021 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2016-03-06 14:38:20 16021 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '10.1.33.13:4444/xtrabackup_sst//1' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/data/' --defaults-file '/etc/mysql/my.cnf' --defaults-group-suffix '' '' --gtid '659aca7c-e1d4-11e5-a961-4a178457e29f:25900366''
2016-03-06 14:38:21 16021 [Note] WSREP: sst_donor_thread signaled with 0
WSREP_SST: [INFO] Streaming with xbstream (20160306 14:38:21.501)
WSREP_SST: [INFO] Using socat as streamer (20160306 14:38:21.505)
WSREP_SST: [INFO] Using /tmp/tmp.Qov1EfWyFQ as xtrabackup temporary directory (20160306 14:38:21.552)
WSREP_SST: [INFO] Using /tmp/tmp.cibRzaStrS as innobackupex temporary directory (20160306 14:38:21.557)
WSREP_SST: [INFO] Streaming GTID file before SST (20160306 14:38:21.563)
WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | socat -u stdio TCP:10.1.33.13:4444; RC=( ${PIPESTATUS[@]} ) (20160306 14:38:21.567)
WSREP_SST: [INFO] Sleeping before data transfer for SST (20160306 14:38:21.573)
WSREP_SST: [INFO] Streaming the backup to joiner at 10.1.33.13 4444 (20160306 14:38:31.579)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/mysql/my.cnf --defaults-group=mysqld --no-version-check $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio TCP:10.1.33.13:4444; RC=( ${PIPESTATUS[@]} ) (20160306 14:38:31.589)

# But failed after a small performance hiccup

2016-03-06 15:20:51 16021 [Warning] WSREP: last inactive check more than PT1.5S ago (PT1.88089S), skipping check
2016-03-06 15:21:15 16021 [ERROR] WSREP: FSM: no such a transition COMMITTING -> REPLICATING
21:21:15 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 XtraDB Cluster better by reporting any
bugs at https://bugs.launchpad.net/percona-xtradb-cluster

# And the backtrace shows a SELECT going on ??
Thread pointer: 0x2679aa0
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 = 7fb8446b2e00 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0x9230ac]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x69c5b1]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7fc8d5ea6340]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39)[0x7fc8d52e7cc9]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7fc8d52eb0d8]
/usr/lib/libgalera_smm.so(_ZN6galera3FSMINS_9TrxHandle5StateENS1_10TransitionENS_10EmptyGuardENS_11EmptyActionEE8shift_toES2_+0x199)[0x7fc8a3720ba9]
/usr/lib/libgalera_smm.so(_ZN6galera13ReplicatorSMM9replicateEPNS_9TrxHandleEP14wsrep_trx_meta+0x185)[0x7fc8a3716b15]
/usr/lib/libgalera_smm.so(galera_pre_commit+0xb3)[0x7fc8a3728e13]
/usr/sbin/mysqld(_Z22wsrep_run_wsrep_commitP3THDP10handlertonb+0x868)[0x7cb178]
/usr/sbin/mysqld(_Z14ha_prepare_lowP3THDb+0x80)[0x5dce70]
/usr/sbin/mysqld(_Z15ha_commit_transP3THDbb+0x214)[0x5dc1a4]
/usr/sbin/mysqld(_Z17trans_commit_stmtP3THD+0x37)[0x7af857]
/usr/sbin/mysqld(_ZN13select_create8send_eofEv+0x6d)[0x707d9d]
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x48d)[0x6fd96d]
/usr/sbin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_P10SQL_I_ListI8st_orderESB_S7_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x275)[0x74ad75]
/usr/sbin/mysqld(_Z13handle_selectP3THDP13select_resultm+0x165)[0x74b5d5]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x63b2)[0x726ab2]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x5e8)[0x728408]
/usr/sbin/mysqld[0x728c51]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1bf2)[0x72b0a2]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x244)[0x72cba4]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x172)[0x6f44f2]
/usr/sbin/mysqld(handle_one_connection+0x40)[0x6f46e0]
/usr/sbin/mysqld(pfs_spawn_thread+0x143)[0xb41a13]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7fc8d5e9e182]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fc8d53ab47d]

And the query section of the crash report shows a CREATE TABLE was ongoing;

Some pointers may be invalid and cause the dump to abort.
Query (7fb6e4016d10): /* PDO: */ CREATE TABLE ...|

Still need to confirm with customer regarding STATEMENT...