[MDEV-8870] Crash - null pointer exception Created: 2015-09-30  Updated: 2020-10-20  Resolved: 2020-10-20

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.0.21
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: michael vo Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: None
Environment:

linux - google cloud instance
3.16.0-0.bpo.4-amd64, #1 SMP Debian 3.16.7-ckt11-1+deb8u3~bpo70+1 (2015-08-08), x86_64


Issue Links:
Relates
relates to MDEV-15972 Slave Data Mismatch Open

 Description   

It looks like a null pointer exception. The instance crashed.
The number of processes running that match "/usr/sbin/mysql" on db-master-prod-b are below the threshold of 1

Sep 28 23:11:54 db-master-prod-b mysqld: InnoDB: We intentionally generate a memory trap.
Sep 28 23:11:54 db-master-prod-b mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Sep 28 23:11:54 db-master-prod-b mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Sep 28 23:11:54 db-master-prod-b mysqld: InnoDB: immediately after the mysqld startup, there may be
Sep 28 23:11:54 db-master-prod-b mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Sep 28 23:11:54 db-master-prod-b mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Sep 28 23:11:54 db-master-prod-b mysqld: InnoDB: about forcing recovery.
Sep 28 23:11:54 db-master-prod-b mysqld: 150928 23:11:54 [ERROR] mysqld got signal 6 ;
Sep 28 23:11:54 db-master-prod-b mysqld: This could be because you hit a bug. It is also possible that this binary
Sep 28 23:11:54 db-master-prod-b mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Sep 28 23:11:54 db-master-prod-b mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Sep 28 23:11:54 db-master-prod-b mysqld: 
Sep 28 23:11:54 db-master-prod-b mysqld: To report this bug, see http://kb.askmonty.org/en/reporting-bugs
Sep 28 23:11:54 db-master-prod-b mysqld: 
Sep 28 23:11:54 db-master-prod-b mysqld: We will try our best to scrape up some info that will hopefully help
Sep 28 23:11:54 db-master-prod-b mysqld: diagnose the problem, but since we have already crashed, 
Sep 28 23:11:54 db-master-prod-b mysqld: something is definitely wrong and this may fail.
Sep 28 23:11:54 db-master-prod-b mysqld: 
Sep 28 23:11:54 db-master-prod-b mysqld: Server version: 10.0.21-MariaDB-1~wheezy-wsrep-log
Sep 28 23:11:54 db-master-prod-b mysqld: key_buffer_size=134217728
Sep 28 23:11:54 db-master-prod-b mysqld: read_buffer_size=2097152
Sep 28 23:11:54 db-master-prod-b mysqld: max_used_connections=30
Sep 28 23:11:54 db-master-prod-b mysqld: max_threads=102
Sep 28 23:11:54 db-master-prod-b mysqld: thread_count=19
Sep 28 23:11:54 db-master-prod-b mysqld: It is possible that mysqld could use up to 
Sep 28 23:11:54 db-master-prod-b mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2013173 K  bytes of memory
Sep 28 23:11:54 db-master-prod-b mysqld: Hope that's ok; if not, decrease some variables in the equation.
Sep 28 23:11:54 db-master-prod-b mysqld: 
Sep 28 23:11:54 db-master-prod-b mysqld: Thread pointer: 0x0x7f1eb4077008
Sep 28 23:11:54 db-master-prod-b mysqld: Attempting backtrace. You can use the following information to find out
Sep 28 23:11:54 db-master-prod-b mysqld: where mysqld died. If you see no messages after this, something went
Sep 28 23:11:54 db-master-prod-b mysqld: terribly wrong...
Sep 28 23:11:54 db-master-prod-b mysqld: stack_bottom = 0x7f21c4bfdd5f thread_stack 0x48000
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2b)[0x7f21dbc6b44b]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x422)[0x7f21db7e77e2]
Sep 28 23:11:54 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf0a0)[0x7f21dae080a0]
Sep 28 23:11:54 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7f21d9462165]
Sep 28 23:11:54 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x180)[0x7f21d94653e0]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x83cda5)[0x7f21dba73da5]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x7473c2)[0x7f21db97e3c2]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x5b2016)[0x7f21db7e9016]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z15ha_commit_transP3THDb+0x286)[0x7f21db7eac66]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z17trans_commit_stmtP3THD+0x29)[0x7f21db74e139]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x425)[0x7f21db66fb35]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt9exec_coreEP3THDPj+0x1e)[0x7f21db8e622e]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x8e)[0x7f21db8eb9ee]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x15d)[0x7f21db8ebedd]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN7sp_head7executeEP3THDb+0x739)[0x7f21db8e95e9]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x626)[0x7f21db8ea8d6]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN14Event_job_data7executeEP3THDb+0x56f)[0x7f21db72aaaf]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN19Event_worker_thread3runEP3THDP28Event_queue_element_for_exec+0x119)[0x7f21db91bda9]
Sep 28 23:11:54 db-master-prod-b mysqld: /usr/sbin/mysqld(event_worker_thread+0x56)[0x7f21db91be46]
Sep 28 23:11:54 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7f21dadffb50]
Sep 28 23:11:54 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f21d950b95d]
Sep 28 23:11:54 db-master-prod-b mysqld: 
Sep 28 23:11:54 db-master-prod-b mysqld: Trying to get some variables.
Sep 28 23:11:54 db-master-prod-b mysqld: Some pointers may be invalid and cause the dump to abort.
Sep 28 23:11:54 db-master-prod-b mysqld: Query (0x7f1eb9121020): is an invalid pointer
Sep 28 23:11:54 db-master-prod-b mysqld: Connection ID (thread ID): 369097
Sep 28 23:11:54 db-master-prod-b mysqld: Status: NOT_KILLED
Sep 28 23:11:54 db-master-prod-b mysqld: 
Sep 28 23:11:54 db-master-prod-b mysqld: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on
Sep 28 23:11:54 db-master-prod-b mysqld: 
Sep 28 23:11:54 db-master-prod-b mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Sep 28 23:11:54 db-master-prod-b mysqld: information that should help you find out what is causing the crash.
Sep 28 23:11:58 db-master-prod-b mysqld_safe: Number of processes running now: 0
Sep 28 23:11:58 db-master-prod-b mysqld_safe: WSREP: not restarting wsrep node automatically
Sep 28 23:11:58 db-master-prod-b mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
Sep 28 23:12:50 db-master-prod-b collectd[3005]: mysql plugin: Lost connection to instance "tock_prod": MySQL server has gone away
Sep 28 23:12:50 db-master-prod-b collectd[3005]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Sep 28 23:12:50 db-master-prod-b collectd[3005]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 120.000 seconds.
Sep 28 23:14:50 db-master-prod-b collectd[3005]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Sep 28 23:14:50 db-master-prod-b collectd[3005]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 240.000 seconds.
Sep 28 23:17:01 db-master-prod-b /USR/SBIN/CRON[3693]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Sep 28 23:18:50 db-master-prod-b collectd[3005]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Sep 28 23:18:50 db-master-prod-b collectd[3005]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 480.000 seconds.
Sep 28 23:26:50 db-master-prod-b collectd[3005]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Sep 28 23:26:50 db-master-prod-b collectd[3005]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 960.000 seconds.
Sep 28 23:30:30 db-master-prod-b mysqld_safe: Starting mysqld daemon with databases from /var/lib/mysql
Sep 28 23:30:30 db-master-prod-b mysqld_safe: WSREP: Running position recovery with --log_error='/var/lib/mysql/wsrep_recovery.TW6WRH' --pid-file='/var/lib/mysql/db-master-prod-b-recover.pid'
Sep 28 23:30:30 db-master-prod-b mysqld: 150928 23:30:30 [Note] /usr/sbin/mysqld (mysqld 10.0.21-MariaDB-1~wheezy-wsrep-log) starting as process 4333 ...
Sep 28 23:30:39 db-master-prod-b mysqld_safe: WSREP: Recovered position a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2144078
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] /usr/sbin/mysqld (mysqld 10.0.21-MariaDB-1~wheezy-wsrep-log) starting as process 4514 ...
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Read nil XID from storage engines, skipping position init
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: wsrep_load(): Galera 3.9(rXXXX) by Codership Oy <info@codership.com> loaded successfully.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: CRC-32C: using hardware acceleration.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Found saved state: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:-1
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Passing config to GCS: base_host = 10.240.115.41; base_port = 4567; cert.log_conflicts = no; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false; pc.ignore_sb = false; pc.
Sep 28 23:30:39 db-master-prod-b mysqld: npvo = false; pc.recove
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Service thread queue flushed.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Assign initial position for certification: 2144078, protocol version: -1
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: wsrep_sst_grab()
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Start replication
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Setting initial position to a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2144078
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: protonet asio version 0
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Using CRC-32C for message checksums.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: backend: asio
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: restore pc from disk successfully
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: GMCast version 0
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: (0b544c33, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: (0b544c33, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: EVS version 0
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: gcomm: connecting to group 'tock_db_cluster_prod', peer 'db-master-prod-a:,db-master-prod-b:,db-master-prod-c:'
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Warning] WSREP: (0b544c33, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' points to own listening address, blacklisting
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: (0b544c33, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' pointing to uuid 0b544c33 is blacklisted, skipping
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: (0b544c33, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: (0b544c33, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' pointing to uuid 0b544c33 is blacklisted, skipping
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: (0b544c33, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' pointing to uuid 0b544c33 is blacklisted, skipping
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: (0b544c33, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' pointing to uuid 0b544c33 is blacklisted, skipping
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: declaring 3e8a20de at tcp://10.240.12.54:4567 stable
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: declaring 7c11e4e6 at tcp://10.240.173.81:4567 stable
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Node 3e8a20de state prim
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: view(view_id(PRIM,0b544c33,111) memb {
Sep 28 23:30:39 db-master-prod-b mysqld: #0110b544c33,0
Sep 28 23:30:39 db-master-prod-b mysqld: #0113e8a20de,0
Sep 28 23:30:39 db-master-prod-b mysqld: #0117c11e4e6,0
Sep 28 23:30:39 db-master-prod-b mysqld: } joined {
Sep 28 23:30:39 db-master-prod-b mysqld: } left {
Sep 28 23:30:39 db-master-prod-b mysqld: } partitioned {
Sep 28 23:30:39 db-master-prod-b mysqld: })
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: save pc into disk
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: clear restored view
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: gcomm: connected
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Opened channel 'tock_db_cluster_prod'
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Waiting for SST to complete.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: STATE_EXCHANGE: sent state UUID: edc923c9-6638-11e5-b27c-2ff4c624316d
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: STATE EXCHANGE: sent state msg: edc923c9-6638-11e5-b27c-2ff4c624316d
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: STATE EXCHANGE: got state msg: edc923c9-6638-11e5-b27c-2ff4c624316d from 0 (db-master-prod-b)
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: STATE EXCHANGE: got state msg: edc923c9-6638-11e5-b27c-2ff4c624316d from 1 (db-master-prod-c)
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: STATE EXCHANGE: got state msg: edc923c9-6638-11e5-b27c-2ff4c624316d from 2 (db-master-prod-a)
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Quorum results:
Sep 28 23:30:39 db-master-prod-b mysqld: #011version    = 3,
Sep 28 23:30:39 db-master-prod-b mysqld: #011component  = PRIMARY,
Sep 28 23:30:39 db-master-prod-b mysqld: #011conf_id    = 106,
Sep 28 23:30:39 db-master-prod-b mysqld: #011members    = 2/3 (joined/total),
Sep 28 23:30:39 db-master-prod-b mysqld: #011act_id     = 2144109,
Sep 28 23:30:39 db-master-prod-b mysqld: #011last_appl. = -1,
Sep 28 23:30:39 db-master-prod-b mysqld: #011protocols  = 0/7/3 (gcs/repl/appl),
Sep 28 23:30:39 db-master-prod-b mysqld: #011group UUID = a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Flow-control interval: [28, 28]
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 2144109)
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: State transfer required: 
Sep 28 23:30:39 db-master-prod-b mysqld: #011Group state: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2144109
Sep 28 23:30:39 db-master-prod-b mysqld: #011Local state: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2144078
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: New cluster view: global state: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2144109, view# 107: Primary, number of nodes: 3, my index: 0, protocol version 3
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Warning] WSREP: Gap in state sequence. Need state transfer.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '10.240.115.41' --auth '' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --defaults-group-suffix '' --parent '4514' --binlog '/var/log/mysql/mariadb-bin' '
Sep 28 23:30:39 db-master-prod-b rsyncd[4557]: rsyncd version 3.0.9 starting, listening on port 4444
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Prepared SST request: rsync|10.240.115.41:4444/rsync_sst
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: REPL Protocols: 7 (3, 2)
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Service thread queue flushed.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Assign initial position for certification: 2144109, protocol version: 3
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Service thread queue flushed.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Prepared IST receiver, listening at: tcp://10.240.115.41:4568
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Member 0.0 (db-master-prod-b) requested state transfer from '*any*'. Selected 1.0 (db-master-prod-c)(SYNCED) as donor.
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 2144109)
Sep 28 23:30:39 db-master-prod-b mysqld: 150928 23:30:39 [Note] WSREP: Requesting state transfer: success, donor: 1
Sep 28 23:30:39 db-master-prod-b rsyncd[4573]: connect from db-master-prod-c.c.rapid-depot-817.internal (10.240.12.54)
Sep 28 23:30:39 db-master-prod-b rsyncd[4573]: rsync to rsync_sst/ from db-master-prod-c.c.rapid-depot-817.internal (10.240.12.54)
Sep 28 23:30:39 db-master-prod-b rsyncd[4573]: receiving file list
Sep 28 23:30:40 db-master-prod-b mysqld: 150928 23:30:40 [Note] WSREP: 1.0 (db-master-prod-c): State transfer to 0.0 (db-master-prod-b) complete.
Sep 28 23:30:40 db-master-prod-b mysqld: 150928 23:30:40 [Note] WSREP: Member 1.0 (db-master-prod-c) synced with group.
Sep 28 23:30:40 db-master-prod-b rsyncd[4573]: sent 54 bytes  received 180 bytes  total size 45
Sep 28 23:30:40 db-master-prod-b mysqld: WSREP_SST: [INFO] Joiner cleanup. (20150928 23:30:40.876)
Sep 28 23:30:41 db-master-prod-b rsyncd[4557]: rsync error: received SIGINT, SIGTERM, or SIGHUP (code 20) at rsync.c(549) [Receiver=3.0.9]
Sep 28 23:30:41 db-master-prod-b mysqld: WSREP_SST: [INFO] Joiner cleanup done. (20150928 23:30:41.381)
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] WSREP: SST complete, seqno: 2144078
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: Using mutexes to ref count buffer pool pages
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: The InnoDB memory heap is disabled
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: Memory barrier is not used
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: Compressed tables use zlib 1.2.7
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: Using Linux native AIO
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: Using CPU crc32 instructions
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: Initializing buffer pool, size = 10.0G
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: Completed initialization of buffer pool
Sep 28 23:30:41 db-master-prod-b mysqld: 150928 23:30:41 [Note] InnoDB: Highest supported file format is Barracuda.
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] InnoDB: 128 rollback segment(s) are active.
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] InnoDB: Waiting for purge to start
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.25-73.1 started; log sequence number 3290481818
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] Plugin 'FEEDBACK' is disabled.
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] Server socket created on IP: '0.0.0.0'.
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [ERROR] mysqld: Table './mysql/event' is marked as crashed and should be repaired
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [ERROR] mysqld: Table 'event' is marked as crashed and should be repaired
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Warning] Checking table:   './mysql/event'
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [ERROR] mysql.event: 1 client is using or hasn't closed the table properly
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] Event Scheduler: Loaded 1 event
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: Signalling provider to continue.
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: SST received: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2144078
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: Receiving IST: 31 writesets, seqnos 2144078-2144109
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] Event Scheduler: scheduler thread started with id 4
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] Reading of all Master_info entries succeded
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] Added new Master_info '' to hash table
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] /usr/sbin/mysqld: ready for connections.
Sep 28 23:30:42 db-master-prod-b mysqld: Version: '10.0.21-MariaDB-1~wheezy-wsrep-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution, wsrep_25.10.r4144
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: IST received: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2144109
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: 0.0 (db-master-prod-b): State transfer from 1.0 (db-master-prod-c) complete.
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: Shifting JOINER -> JOINED (TO: 2144109)
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: Member 0.0 (db-master-prod-b) synced with group.
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 2144109)
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: Synchronized with group, ready for connections
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Sep 28 23:30:42 db-master-prod-b mysqld: 150928 23:30:42 [Note] WSREP: (0b544c33, 'tcp://0.0.0.0:4567') turning message relay requesting off
Sep 28 23:30:43 db-master-prod-b /etc/mysql/debian-start[4808]: Upgrading MySQL tables if necessary.
Sep 28 23:30:43 db-master-prod-b /etc/mysql/debian-start[4812]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored
Sep 28 23:30:43 db-master-prod-b /etc/mysql/debian-start[4812]: Looking for 'mysql' as: /usr/bin/mysql
Sep 28 23:30:43 db-master-prod-b /etc/mysql/debian-start[4812]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Sep 28 23:30:43 db-master-prod-b /etc/mysql/debian-start[4812]: This installation of MySQL is already upgraded to 10.0.21-MariaDB, use --force if you still need to run mysql_upgrade
Sep 28 23:30:43 db-master-prod-b /etc/mysql/debian-start[4823]: Checking for insecure root accounts.
Sep 28 23:30:43 db-master-prod-b /etc/mysql/debian-start[4827]: Triggering myisam-recover for all MyISAM tables
Sep 28 23:30:52 db-master-prod-b mysqld: 150928 23:30:52 [Warning] IP address '10.52.2.3' could not be resolved: Name or service not known
Sep 28 23:30:54 db-master-prod-b mysqld: 150928 23:30:54 [Warning] IP address '10.68.2.3' could not be resolved: Name or service not known
Sep 28 23:30:56 db-master-prod-b mysqld: 150928 23:30:56 [Warning] IP address '10.68.0.3' could not be resolved: Name or service not known
Sep 28 23:30:57 db-master-prod-b mysqld: 150928 23:30:57 [Warning] IP address '10.68.1.3' could not be resolved: Name or service not known
Sep 28 23:31:25 db-master-prod-b mysqld: 150928 23:31:25 [Warning] IP address '10.52.0.3' could not be resolved: Name or service not known
Sep 28 23:31:28 db-master-prod-b mysqld: 150928 23:31:28 [Warning] IP address '10.52.1.3' could not be resolved: Name or service not known
Sep 28 23:42:50 db-master-prod-b collectd[3005]: mysql plugin: Successfully connected to database <none> at server Localhost via UNIX socket (server version: 10.0.21-MariaDB-1~wheezy-wsrep-log, protocol version: 10)



 Comments   
Comment by Elena Stepanova [ 2015-09-30 ]

Please quote a part of the log before "InnoDB: We intentionally generate a memory trap." (at least 10-20 lines, the more the better).
Thanks.

Comment by Robin Anil [ 2015-09-30 ]

Here is the missing line. Nothing in the syslog before that.

Sep 28 22:31:00 db-master-prod-b collectd[3005]: write_http plugin: curl_easy_perform failed with status 28: SSL connection timeout
Sep 28 22:38:01 db-master-prod-b collectd[3005]: write_http plugin: curl_easy_perform failed with status 28: SSL connection timeout
Sep 28 23:11:54 db-master-prod-b mysqld: 2015-09-28 23:11:54 7f21c4bfe700  InnoDB: Assertion failure in thread 139783011559168 in file trx0trx.cc line 1999

Comment by JJ Lueck [ 2016-02-26 ]

Hi Elena.

We had our second incident of a null pointer crash, very similar to the crash back in September of last year.

I've included the relevant portion of the syslog, please let me know what else I can provide if you're looking into this particular issue.

Thanks.


Show all

Feb 25 19:52:21 db-master-prod-b mysqld: 2016-02-25 19:52:21 7f3b45c49700 InnoDB: Assertion failure in thread 139892550309632 in file lock0lock.cc line 2025
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: We intentionally generate a memory trap.
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: immediately after the mysqld startup, there may be
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: about forcing recovery.
Feb 25 19:52:21 db-master-prod-b mysqld: 160225 19:52:21 [ERROR] mysqld got signal 6 ;
Feb 25 19:52:21 db-master-prod-b mysqld: This could be because you hit a bug. It is also possible that this binary
Feb 25 19:52:21 db-master-prod-b mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Feb 25 19:52:21 db-master-prod-b mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: To report this bug, see http://kb.askmonty.org/en/reporting-bugs
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: We will try our best to scrape up some info that will hopefully help
Feb 25 19:52:21 db-master-prod-b mysqld: diagnose the problem, but since we have already crashed,
Feb 25 19:52:21 db-master-prod-b mysqld: something is definitely wrong and this may fail.
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: Server version: 10.0.22-MariaDB-1~wheezy-wsrep-log
Feb 25 19:52:21 db-master-prod-b mysqld: key_buffer_size=134217728
Feb 25 19:52:21 db-master-prod-b mysqld: read_buffer_size=2097152
Feb 25 19:52:21 db-master-prod-b mysqld: max_used_connections=77
Feb 25 19:52:21 db-master-prod-b mysqld: max_threads=1002
Feb 25 19:52:21 db-master-prod-b mysqld: thread_count=44
Feb 25 19:52:21 db-master-prod-b mysqld: It is possible that mysqld could use up to
Feb 25 19:52:21 db-master-prod-b mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18620128 K bytes of memory
Feb 25 19:52:21 db-master-prod-b mysqld: Hope that's ok; if not, decrease some variables in the equation.
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: Thread pointer: 0x0x7f390498e008
Feb 25 19:52:21 db-master-prod-b mysqld: Attempting backtrace. You can use the following information to find out
Feb 25 19:52:21 db-master-prod-b mysqld: where mysqld died. If you see no messages after this, something went
Feb 25 19:52:21 db-master-prod-b mysqld: terribly wrong...
Feb 25 19:52:21 db-master-prod-b mysqld: stack_bottom = 0x7f3b45c48d5f thread_stack 0x48000
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2b)[0x7f3c6084bd7b]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x422)[0x7f3c603c8852]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf0a0)[0x7f3c5f9e60a0]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7f3c5e040165]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x180)[0x7f3c5e0433e0]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x783cf0)[0x7f3c60598cf0]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x78488e)[0x7f3c6059988e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x78883e)[0x7f3c6059d83e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x80c796)[0x7f3c60621796]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x7584cf)[0x7f3c6056d4cf]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN7handler18ha_index_next_sameEPhPKhj+0x13c)[0x7f3c603ce2dc]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x464d7e)[0x7f3c60279d7e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x1b2)[0x7f3c6027b002]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x47da3d)[0x7f3c60292a3d]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN4JOIN10exec_innerEv+0xa6c)[0x7f3c602a60cc]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN4JOIN4execEv+0x11)[0x7f3c602a7ea1]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x1dd)[0x7f3c602a4abd]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z18mysql_multi_updateP3THDP10TABLE_LISTP4ListI4ItemES6_PS4_y15enum_duplicatesbP18st_select_lex_unitP13st_select_lexPP12multi_update+0x1c0)[0x7f3c602ed050]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x6b8f)[0x7f3c60255e9f]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt9exec_coreEP3THDPj+0x1e)[0x7f3c604c697e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x8e)[0x7f3c604cc13e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x15d)[0x7f3c604cc62d]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN7sp_head7executeEP3THDb+0x739)[0x7f3c604c9d39]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x626)[0x7f3c604cb026]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN14Event_job_data7executeEP3THDb+0x56f)[0x7f3c6030ab0f]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN19Event_worker_thread3runEP3THDP28Event_queue_element_for_exec+0x119)[0x7f3c604fc629]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(event_worker_thread+0x56)[0x7f3c604fc6c6]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7f3c5f9ddb50]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f3c5e0e995d]
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: Trying to get some variables.
Feb 25 19:52:21 db-master-prod-b mysqld: Some pointers may be invalid and cause the dump to abort.
Feb 25 19:52:21 db-master-prod-b mysqld: Query (0x7f393b90b020): is an invalid pointer
Feb 25 19:52:21 db-master-prod-b mysqld: Connection ID (thread ID): 460672
Feb 25 19:52:21 db-master-prod-b mysqld: Status: NOT_KILLED
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosesca
n=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_bu
ffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Feb 25 19:52:21 db-master-prod-b mysqld: information that should help you find out what is causing the crash.
Feb 25 19:52:26 db-master-prod-b mysqld_safe: Number of processes running now: 0
Feb 25 19:52:26 db-master-prod-b mysqld_safe: WSREP: not restarting wsrep node automatically
Feb 25 19:52:26 db-master-prod-b mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
Feb 25 19:52:48 db-master-prod-b collectd[9240]: mysql plugin: Lost connection to instance "tock_prod": MySQL server has gone away

Comment by JJ Lueck [ 2016-02-26 ]

Hi Elena.

We had a second instance of a null pointer crash which is very similar to the one reported back in September of last year. I've included the relevant information from the syslog.

Let me know if there are other items you'd like me to collect from around the time of the crash if it will help in understanding the issue.

Thanks!

Feb 25 19:52:21 db-master-prod-b mysqld: 2016-02-25 19:52:21 7f3b45c49700 InnoDB: Assertion failure in thread 139892550309632 in file lock0lock.cc line 2025
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: We intentionally generate a memory trap.
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: immediately after the mysqld startup, there may be
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Feb 25 19:52:21 db-master-prod-b mysqld: InnoDB: about forcing recovery.
Feb 25 19:52:21 db-master-prod-b mysqld: 160225 19:52:21 [ERROR] mysqld got signal 6 ;
Feb 25 19:52:21 db-master-prod-b mysqld: This could be because you hit a bug. It is also possible that this binary
Feb 25 19:52:21 db-master-prod-b mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Feb 25 19:52:21 db-master-prod-b mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: To report this bug, see http://kb.askmonty.org/en/reporting-bugs
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: We will try our best to scrape up some info that will hopefully help
Feb 25 19:52:21 db-master-prod-b mysqld: diagnose the problem, but since we have already crashed,
Feb 25 19:52:21 db-master-prod-b mysqld: something is definitely wrong and this may fail.
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: Server version: 10.0.22-MariaDB-1~wheezy-wsrep-log
Feb 25 19:52:21 db-master-prod-b mysqld: key_buffer_size=134217728
Feb 25 19:52:21 db-master-prod-b mysqld: read_buffer_size=2097152
Feb 25 19:52:21 db-master-prod-b mysqld: max_used_connections=77
Feb 25 19:52:21 db-master-prod-b mysqld: max_threads=1002
Feb 25 19:52:21 db-master-prod-b mysqld: thread_count=44
Feb 25 19:52:21 db-master-prod-b mysqld: It is possible that mysqld could use up to
Feb 25 19:52:21 db-master-prod-b mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18620128 K bytes of memory
Feb 25 19:52:21 db-master-prod-b mysqld: Hope that's ok; if not, decrease some variables in the equation.
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: Thread pointer: 0x0x7f390498e008
Feb 25 19:52:21 db-master-prod-b mysqld: Attempting backtrace. You can use the following information to find out
Feb 25 19:52:21 db-master-prod-b mysqld: where mysqld died. If you see no messages after this, something went
Feb 25 19:52:21 db-master-prod-b mysqld: terribly wrong...
Feb 25 19:52:21 db-master-prod-b mysqld: stack_bottom = 0x7f3b45c48d5f thread_stack 0x48000
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2b)[0x7f3c6084bd7b]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x422)[0x7f3c603c8852]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf0a0)[0x7f3c5f9e60a0]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7f3c5e040165]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x180)[0x7f3c5e0433e0]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x783cf0)[0x7f3c60598cf0]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x78488e)[0x7f3c6059988e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x78883e)[0x7f3c6059d83e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x80c796)[0x7f3c60621796]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x7584cf)[0x7f3c6056d4cf]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN7handler18ha_index_next_sameEPhPKhj+0x13c)[0x7f3c603ce2dc]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x464d7e)[0x7f3c60279d7e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x1b2)[0x7f3c6027b002]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x47da3d)[0x7f3c60292a3d]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN4JOIN10exec_innerEv+0xa6c)[0x7f3c602a60cc]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN4JOIN4execEv+0x11)[0x7f3c602a7ea1]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x1dd)[0x7f3c602a4abd]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z18mysql_multi_updateP3THDP10TABLE_LISTP4ListI4ItemES6_PS4_y15enum_duplicatesbP18st_select_lex_unitP13st_select_lexPP12multi_update+0x1c0)[0x7f3c602ed050]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x6b8f)[0x7f3c60255e9f]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt9exec_coreEP3THDPj+0x1e)[0x7f3c604c697e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x8e)[0x7f3c604cc13e]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x15d)[0x7f3c604cc62d]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN7sp_head7executeEP3THDb+0x739)[0x7f3c604c9d39]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x626)[0x7f3c604cb026]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN14Event_job_data7executeEP3THDb+0x56f)[0x7f3c6030ab0f]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_ZN19Event_worker_thread3runEP3THDP28Event_queue_element_for_exec+0x119)[0x7f3c604fc629]
Feb 25 19:52:21 db-master-prod-b mysqld: /usr/sbin/mysqld(event_worker_thread+0x56)[0x7f3c604fc6c6]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7f3c5f9ddb50]
Feb 25 19:52:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f3c5e0e995d]
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: Trying to get some variables.
Feb 25 19:52:21 db-master-prod-b mysqld: Some pointers may be invalid and cause the dump to abort.
Feb 25 19:52:21 db-master-prod-b mysqld: Query (0x7f393b90b020): is an invalid pointer
Feb 25 19:52:21 db-master-prod-b mysqld: Connection ID (thread ID): 460672
Feb 25 19:52:21 db-master-prod-b mysqld: Status: NOT_KILLED
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosesca
n=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_bu
ffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on
Feb 25 19:52:21 db-master-prod-b mysqld:
Feb 25 19:52:21 db-master-prod-b mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Feb 25 19:52:21 db-master-prod-b mysqld: information that should help you find out what is causing the crash.
Feb 25 19:52:26 db-master-prod-b mysqld_safe: Number of processes running now: 0
Feb 25 19:52:26 db-master-prod-b mysqld_safe: WSREP: not restarting wsrep node automatically
Feb 25 19:52:26 db-master-prod-b mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
Feb 25 19:52:48 db-master-prod-b collectd[9240]: mysql plugin: Lost connection to instance "tock_prod": MySQL server has gone away

Comment by Elena Stepanova [ 2016-03-04 ]

jlueck-tock, thanks.

So, both times the problem happen inside some event. Can you find out which event runs around the time of the failure? It should do a multi-table update.

If you can provide a data dump of the schema where it runs, it will of course be a huge help – if it's possible, you can download it to ftp.askmonty.org/private, only MariaDB developers will have access to it.

Otherwise, If you find the event, please paste or attach structures (SHOW CREATE output) for the event itself and all objects – tables, procedures, anything – that it is using.
For tables, SHOW INDEX IN might be useful, too.

Please also attach your cnf file(s).

Thanks.

Comment by JJ Lueck [ 2016-03-04 ]

Hi Elena.

We only have one event that fires in our database setup but it does do a multi-table update. Below is the information about the event, the relevant tables, and the indices on those tables. Let me know if anything looks out of sorts of if this points you in the right direction.

> show create event unlock_tickets\G
*************************** 1. row ***************************
               Event: unlock_tickets
            sql_mode: NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION
           time_zone: SYSTEM
        Create Event: CREATE DEFINER=`tocktix2`@`%` EVENT `unlock_tickets` ON SCHEDULE EVERY 1 MINUTE STARTS '2016-01-13 21:26:21' ON COMPLETION NOT PRESERVE ENABLE COMMENT 'Unlocks any tickets locked but not bought by a patron and sets t' DO BEGIN
          SET SESSION tx_isolation='SERIALIZABLE';
          START TRANSACTION WITH CONSISTENT SNAPSHOT;
          UPDATE ticket t
                JOIN ticket_subset ts ON ts.id = t.ticket_subset_id AND ts.unlock_state = 0
                SET t.ticket_subset_id = NULL, t.locked_by = NULL, t.locked_until = NULL, t.session_lock = NULL
                WHERE t.locked_until IS NOT NULL
                AND t.locked_until < NOW();
          UPDATE ticket t
                JOIN ticket_subset ts ON t.ticket_group_id = ts.ticket_group_id AND ts.state = 1
                JOIN ticket_group tg ON t.ticket_group_id = tg.id
                SET t.ticket_subset_id = ts.id, t.locked_by = NULL, t.locked_until = NULL, t.session_lock = NULL
                WHERE t.locked_until IS NOT NULL
                AND t.locked_until < NOW()
                AND t.ticket_subset_id IS NOT NULL;
          UPDATE ticket t
                JOIN ticket_subset ts ON t.ticket_subset_id = ts.id AND ts.state = 0
                JOIN ticket_group tg ON t.ticket_group_id = tg.id
                SET ts.state = 1, t.locked_by = NULL, t.locked_until = NULL, t.session_lock = NULL
                WHERE t.locked_until IS NOT NULL
                AND t.locked_until < NOW();
          UPDATE ticket_subset
            LEFT OUTER JOIN ticket ON ticket.ticket_subset_id = ticket_subset.id
            SET ticket_subset.ticket_group_id = NULL
            WHERE
              ticket_subset.state = 0 AND
              ticket_subset.ticket_group_id IS NOT NULL
              AND ticket.id IS NULL;
          COMMIT;
        END

show create table ticket\G
*************************** 1. row ***************************
       Table: ticket
Create Table: CREATE TABLE `ticket` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `ticket_group_id` int(10) unsigned DEFAULT NULL,
  `created_at` datetime NOT NULL,
  `updated_at` datetime NOT NULL,
  `session_lock` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
  `locked_by` int(11) DEFAULT NULL,
  `locked_until` datetime DEFAULT NULL,
  `ticket_subset_id` int(10) unsigned DEFAULT NULL,
  `version` int(11) NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`),
  KEY `index_ticket_on_ticket_group_id` (`ticket_group_id`),
  KEY `index_ticket_on_ticket_group_id_and_session_lock` (`ticket_group_id`,`session_lock`) USING BTREE,
  KEY `index_ticket_on_ticket_group_id_and_locked_until` (`ticket_group_id`,`locked_until`) USING BTREE,
  KEY `index_ticket_on_locked_until` (`locked_until`) USING BTREE,
  KEY `index_ticket_on_session_lock` (`session_lock`) USING BTREE,
  KEY `index_ticket_on_ticket_subset_id` (`ticket_subset_id`) USING BTREE,
  CONSTRAINT `fk_rails_49ed58aa86` FOREIGN KEY (`ticket_group_id`) REFERENCES `ticket_group` (`id`),
  CONSTRAINT `fk_rails_d22fa17d27` FOREIGN KEY (`ticket_subset_id`) REFERENCES `ticket_subset` (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=9734042 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci

> show index in ticket\G
*************************** 1. row ***************************
        Table: ticket
   Non_unique: 0
     Key_name: PRIMARY
 Seq_in_index: 1
  Column_name: id
    Collation: A
  Cardinality: 2564273
     Sub_part: NULL
       Packed: NULL
         Null:
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 2. row ***************************
        Table: ticket
   Non_unique: 1
     Key_name: index_ticket_on_ticket_group_id
 Seq_in_index: 1
  Column_name: ticket_group_id
    Collation: A
  Cardinality: 1282136
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 3. row ***************************
        Table: ticket
   Non_unique: 1
     Key_name: index_ticket_on_ticket_group_id_and_session_lock
 Seq_in_index: 1
  Column_name: ticket_group_id
    Collation: A
  Cardinality: 854757
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 4. row ***************************
        Table: ticket
   Non_unique: 1
     Key_name: index_ticket_on_ticket_group_id_and_session_lock
 Seq_in_index: 2
  Column_name: session_lock
    Collation: A
  Cardinality: 854757
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 5. row ***************************
        Table: ticket
   Non_unique: 1
     Key_name: index_ticket_on_ticket_group_id_and_locked_until
 Seq_in_index: 1
  Column_name: ticket_group_id
    Collation: A
  Cardinality: 1282136
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 6. row ***************************
        Table: ticket
   Non_unique: 1
     Key_name: index_ticket_on_ticket_group_id_and_locked_until
 Seq_in_index: 2
  Column_name: locked_until
    Collation: A
  Cardinality: 854757
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 7. row ***************************
        Table: ticket
   Non_unique: 1
     Key_name: index_ticket_on_locked_until
 Seq_in_index: 1
  Column_name: locked_until
    Collation: A
  Cardinality: 26
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 8. row ***************************
        Table: ticket
   Non_unique: 1
     Key_name: index_ticket_on_session_lock
 Seq_in_index: 1
  Column_name: session_lock
    Collation: A
  Cardinality: 14
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 9. row ***************************
        Table: ticket
   Non_unique: 1
     Key_name: index_ticket_on_ticket_subset_id
 Seq_in_index: 1
  Column_name: ticket_subset_id
    Collation: A
  Cardinality: 142459
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
9 rows in set (0.05 sec)

 
> show create table ticket_subset\G
*************************** 1. row ***************************
       Table: ticket_subset
Create Table: CREATE TABLE `ticket_subset` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `ticket_group_id` int(10) unsigned DEFAULT NULL,
  `state` tinyint(4) NOT NULL DEFAULT '0',
  `created_at` datetime NOT NULL,
  `updated_at` datetime NOT NULL,
  `unlock_state` tinyint(4) NOT NULL DEFAULT '0',
  `version` int(11) NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`),
  KEY `index_ticket_subset_on_ticket_group_id` (`ticket_group_id`) USING BTREE,
  KEY `index_ticket_subset_on_state` (`state`),
  CONSTRAINT `fk_rails_69108481fa` FOREIGN KEY (`ticket_group_id`) REFERENCES `ticket_group` (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=508566 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci
1 row in set (0.04 sec)

 
> show index in ticket_subset\G
*************************** 1. row ***************************
        Table: ticket_subset
   Non_unique: 0
     Key_name: PRIMARY
 Seq_in_index: 1
  Column_name: id
    Collation: A
  Cardinality: 89349
     Sub_part: NULL
       Packed: NULL
         Null:
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 2. row ***************************
        Table: ticket_subset
   Non_unique: 1
     Key_name: index_ticket_subset_on_ticket_group_id
 Seq_in_index: 1
  Column_name: ticket_group_id
    Collation: A
  Cardinality: 89349
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 3. row ***************************
        Table: ticket_subset
   Non_unique: 1
     Key_name: index_ticket_subset_on_state
 Seq_in_index: 1
  Column_name: state
    Collation: A
  Cardinality: 1
     Sub_part: NULL
       Packed: NULL
         Null:
   Index_type: BTREE
      Comment:
Index_comment:
3 rows in set (0.05 sec)

 
> show create table ticket_group\G
*************************** 1. row ***************************
       Table: ticket_group
Create Table: CREATE TABLE `ticket_group` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `business_id` int(11) DEFAULT NULL,
  `created_at` datetime NOT NULL,
  `updated_at` datetime NOT NULL,
  `date` date NOT NULL,
  `start_time` time NOT NULL,
  `max_size` int(11) NOT NULL,
  `min_purchase_size` int(11) NOT NULL,
  `max_purchase_size` int(11) NOT NULL,
  `service_type` tinyint(4) DEFAULT NULL,
  `is_pristine` tinyint(1) NOT NULL,
  `party_fee_cents` int(11) NOT NULL DEFAULT '0',
  `consumer_visible` tinyint(1) NOT NULL DEFAULT '1',
  `table_variety` int(11) NOT NULL DEFAULT '1',
  `allows_stragglers` tinyint(1) NOT NULL DEFAULT '0',
  `is_archived` tinyint(1) DEFAULT '0',
  `version` int(11) NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`),
  KEY `index_ticket_group_on_business_id` (`business_id`),
  KEY `index_ticket_group_on_business_id_and_date` (`business_id`,`date`),
  KEY `index_ticket_group_on_business_id_and_date_and_start_time` (`business_id`,`date`,`start_time`)
) ENGINE=InnoDB AUTO_INCREMENT=1566776 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci
1 row in set (0.03 sec)

 
> show index in ticket_group\G
*************************** 1. row ***************************
        Table: ticket_group
   Non_unique: 0
     Key_name: PRIMARY
 Seq_in_index: 1
  Column_name: id
    Collation: A
  Cardinality: 517693
     Sub_part: NULL
       Packed: NULL
         Null:
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 2. row ***************************
        Table: ticket_group
   Non_unique: 1
     Key_name: index_ticket_group_on_business_id
 Seq_in_index: 1
  Column_name: business_id
    Collation: A
  Cardinality: 122
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 3. row ***************************
        Table: ticket_group
   Non_unique: 1
     Key_name: index_ticket_group_on_business_id_and_date
 Seq_in_index: 1
  Column_name: business_id
    Collation: A
  Cardinality: 120
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 4. row ***************************
        Table: ticket_group
   Non_unique: 1
     Key_name: index_ticket_group_on_business_id_and_date
 Seq_in_index: 2
  Column_name: date
    Collation: A
  Cardinality: 21570
     Sub_part: NULL
       Packed: NULL
         Null:
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 5. row ***************************
        Table: ticket_group
   Non_unique: 1
     Key_name: index_ticket_group_on_business_id_and_date_and_start_time
 Seq_in_index: 1
  Column_name: business_id
    Collation: A
  Cardinality: 120
     Sub_part: NULL
       Packed: NULL
         Null: YES
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 6. row ***************************
        Table: ticket_group
   Non_unique: 1
     Key_name: index_ticket_group_on_business_id_and_date_and_start_time
 Seq_in_index: 2
  Column_name: date
    Collation: A
  Cardinality: 32355
     Sub_part: NULL
       Packed: NULL
         Null:
   Index_type: BTREE
      Comment:
Index_comment:
*************************** 7. row ***************************
        Table: ticket_group
   Non_unique: 1
     Key_name: index_ticket_group_on_business_id_and_date_and_start_time
 Seq_in_index: 3
  Column_name: start_time
    Collation: A
  Cardinality: 258846
     Sub_part: NULL
       Packed: NULL
         Null:
   Index_type: BTREE
      Comment:
Index_comment:
7 rows in set (0.05 sec)

Comment by Robin Anil [ 2016-03-17 ]

Another crash.

Mar 17 03:51:21 db-master-prod-b mysqld: 2016-03-17 03:51:21 7ffaba119700  InnoDB: Assertion failure in thread 140714840266496 in file trx0trx.cc line 1815
Mar 17 03:51:21 db-master-prod-b mysqld: InnoDB: Failing assertion: trx->lock.n_active_thrs == 1
Mar 17 03:51:21 db-master-prod-b mysqld: InnoDB: We intentionally generate a memory trap.
Mar 17 03:51:21 db-master-prod-b mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Mar 17 03:51:21 db-master-prod-b mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Mar 17 03:51:21 db-master-prod-b mysqld: InnoDB: immediately after the mysqld startup, there may be
Mar 17 03:51:21 db-master-prod-b mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Mar 17 03:51:21 db-master-prod-b mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Mar 17 03:51:21 db-master-prod-b mysqld: InnoDB: about forcing recovery.
Mar 17 03:51:21 db-master-prod-b mysqld: 160317  3:51:21 [ERROR] mysqld got signal 6 ;
Mar 17 03:51:21 db-master-prod-b mysqld: This could be because you hit a bug. It is also possible that this binary
Mar 17 03:51:21 db-master-prod-b mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Mar 17 03:51:21 db-master-prod-b mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Mar 17 03:51:21 db-master-prod-b mysqld: 
Mar 17 03:51:21 db-master-prod-b mysqld: To report this bug, see http://kb.askmonty.org/en/reporting-bugs
Mar 17 03:51:21 db-master-prod-b mysqld: 
Mar 17 03:51:21 db-master-prod-b mysqld: We will try our best to scrape up some info that will hopefully help
Mar 17 03:51:21 db-master-prod-b mysqld: diagnose the problem, but since we have already crashed, 
Mar 17 03:51:21 db-master-prod-b mysqld: something is definitely wrong and this may fail.
Mar 17 03:51:21 db-master-prod-b mysqld: 
Mar 17 03:51:21 db-master-prod-b mysqld: Server version: 10.0.22-MariaDB-1~wheezy-wsrep-log
Mar 17 03:51:21 db-master-prod-b mysqld: key_buffer_size=134217728
Mar 17 03:51:21 db-master-prod-b mysqld: read_buffer_size=2097152
Mar 17 03:51:21 db-master-prod-b mysqld: max_used_connections=74
Mar 17 03:51:21 db-master-prod-b mysqld: max_threads=1002
Mar 17 03:51:21 db-master-prod-b mysqld: thread_count=32
Mar 17 03:51:21 db-master-prod-b mysqld: It is possible that mysqld could use up to 
Mar 17 03:51:21 db-master-prod-b mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18620128 K  bytes of memory
Mar 17 03:51:21 db-master-prod-b mysqld: Hope that's ok; if not, decrease some variables in the equation.
Mar 17 03:51:21 db-master-prod-b mysqld: 
Mar 17 03:51:21 db-master-prod-b mysqld: Thread pointer: 0x0x7ff781a75008
Mar 17 03:51:21 db-master-prod-b mysqld: Attempting backtrace. You can use the following information to find out
Mar 17 03:51:21 db-master-prod-b mysqld: where mysqld died. If you see no messages after this, something went
Mar 17 03:51:21 db-master-prod-b mysqld: terribly wrong...
Mar 17 03:51:21 db-master-prod-b mysqld: stack_bottom = 0x7ff94ad6cd5f thread_stack 0x48000
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2b)[0x7ffab9a56d7b]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x422)[0x7ffab95d3852]
Mar 17 03:51:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf0a0)[0x7ffab8bf10a0]
Mar 17 03:51:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7ffab724b165]
Mar 17 03:51:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x180)[0x7ffab724e3e0]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x83f2eb)[0x7ffab985f2eb]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x838428)[0x7ffab9858428]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x7cd8b8)[0x7ffab97ed8b8]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x83573d)[0x7ffab985573d]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x835a98)[0x7ffab9855a98]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x7473d9)[0x7ffab97673d9]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z17ha_rollback_transP3THDb+0xba)[0x7ffab95d689a]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z14trans_rollbackP3THD+0x4f)[0x7ffab953933f]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(_Z21wsrep_client_rollbackP3THD+0x7c)[0x7ffab957e65c]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(+0x55eec6)[0x7ffab957eec6]
Mar 17 03:51:21 db-master-prod-b mysqld: /usr/sbin/mysqld(start_wsrep_THD+0x375)[0x7ffab93cbd55]
Mar 17 03:51:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7ffab8be8b50]
Mar 17 03:51:21 db-master-prod-b mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7ffab72f495d]
Mar 17 03:51:21 db-master-prod-b mysqld: 
Mar 17 03:51:21 db-master-prod-b mysqld: Trying to get some variables.
Mar 17 03:51:21 db-master-prod-b mysqld: Some pointers may be invalid and cause the dump to abort.
Mar 17 03:51:21 db-master-prod-b mysqld: Query (0x7ff7aa679020): is an invalid pointer
Mar 17 03:51:21 db-master-prod-b mysqld: Connection ID (thread ID): 269894
Mar 17 03:51:21 db-master-prod-b mysqld: Status: NOT_KILLED
Mar 17 03:51:21 db-master-prod-b mysqld: 
Mar 17 03:51:21 db-master-prod-b mysqld: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on
Mar 17 03:51:21 db-master-prod-b mysqld: 
Mar 17 03:51:21 db-master-prod-b mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Mar 17 03:51:21 db-master-prod-b mysqld: information that should help you find out what is causing the crash.
Mar 17 03:51:26 db-master-prod-b mysqld_safe: Number of processes running now: 0
Mar 17 03:51:26 db-master-prod-b mysqld_safe: WSREP: not restarting wsrep node automatically
Mar 17 03:51:26 db-master-prod-b mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
Mar 17 03:51:48 db-master-prod-b collectd[9240]: mysql plugin: Lost connection to instance "tock_prod": MySQL server has gone away
Mar 17 03:51:48 db-master-prod-b collectd[9240]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Mar 17 03:51:48 db-master-prod-b collectd[9240]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 120.000 seconds.
Mar 17 03:53:48 db-master-prod-b collectd[9240]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Mar 17 03:53:48 db-master-prod-b collectd[9240]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 240.000 seconds.
Mar 17 03:57:48 db-master-prod-b collectd[9240]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Mar 17 03:57:48 db-master-prod-b collectd[9240]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 480.000 seconds.
Mar 17 03:58:54 db-master-prod-b mysqld_safe: Starting mysqld daemon with databases from /var/lib/mysql
Mar 17 03:58:54 db-master-prod-b mysqld_safe: WSREP: Running position recovery with --log_error='/var/lib/mysql/wsrep_recovery.bXgo58' --pid-file='/var/lib/mysql/db-master-prod-b-recover.pid'
Mar 17 03:58:54 db-master-prod-b mysqld: 160317  3:58:54 [Note] /usr/sbin/mysqld (mysqld 10.0.22-MariaDB-1~wheezy-wsrep-log) starting as process 21320 ...
Mar 17 03:59:05 db-master-prod-b mysqld_safe: WSREP: Recovered position a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2879285
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] /usr/sbin/mysqld (mysqld 10.0.22-MariaDB-1~wheezy-wsrep-log) starting as process 21511 ...
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Read nil XID from storage engines, skipping position init
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: wsrep_load(): Galera 3.9(rXXXX) by Codership Oy <info@codership.com> loaded successfully.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: CRC-32C: using hardware acceleration.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Found saved state: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:-1
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Passing config to GCS: base_host = 10.240.115.41; base_port = 4567; cert.log_conflicts = no; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false; pc.ignore_sb = false; pc.
Mar 17 03:59:05 db-master-prod-b mysqld: npvo = false; pc.recove
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Service thread queue flushed.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Assign initial position for certification: 2879285, protocol version: -1
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: wsrep_sst_grab()
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Start replication
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Setting initial position to a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2879285
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: protonet asio version 0
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Using CRC-32C for message checksums.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: backend: asio
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: restore pc from disk successfully
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: GMCast version 0
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: (4a110c69, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: (4a110c69, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: EVS version 0
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: gcomm: connecting to group 'tock_db_cluster_prod', peer 'db-master-prod-a:,db-master-prod-b:,db-master-prod-c:'
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Warning] WSREP: (4a110c69, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' points to own listening address, blacklisting
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: (4a110c69, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' pointing to uuid 4a110c69 is blacklisted, skipping
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: (4a110c69, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: (4a110c69, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' pointing to uuid 4a110c69 is blacklisted, skipping
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: (4a110c69, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' pointing to uuid 4a110c69 is blacklisted, skipping
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: (4a110c69, 'tcp://0.0.0.0:4567') address 'tcp://10.240.115.41:4567' pointing to uuid 4a110c69 is blacklisted, skipping
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: declaring 98c30a00 at tcp://10.240.12.54:4567 stable
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: declaring e6f82c4d at tcp://10.240.173.81:4567 stable
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Node 98c30a00 state prim
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: view(view_id(PRIM,4a110c69,222) memb {
Mar 17 03:59:05 db-master-prod-b mysqld: 	4a110c69,0
Mar 17 03:59:05 db-master-prod-b mysqld: 	98c30a00,0
Mar 17 03:59:05 db-master-prod-b mysqld: 	e6f82c4d,0
Mar 17 03:59:05 db-master-prod-b mysqld: } joined {
Mar 17 03:59:05 db-master-prod-b mysqld: } left {
Mar 17 03:59:05 db-master-prod-b mysqld: } partitioned {
Mar 17 03:59:05 db-master-prod-b mysqld: })
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: save pc into disk
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: clear restored view
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: gcomm: connected
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Opened channel 'tock_db_cluster_prod'
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Waiting for SST to complete.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 97c68163-ebf4-11e5-bb11-2687250fe921
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: STATE EXCHANGE: sent state msg: 97c68163-ebf4-11e5-bb11-2687250fe921
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: STATE EXCHANGE: got state msg: 97c68163-ebf4-11e5-bb11-2687250fe921 from 0 (db-master-prod-b)
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: STATE EXCHANGE: got state msg: 97c68163-ebf4-11e5-bb11-2687250fe921 from 1 (db-master-prod-c)
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: STATE EXCHANGE: got state msg: 97c68163-ebf4-11e5-bb11-2687250fe921 from 2 (db-master-prod-a)
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Quorum results:
Mar 17 03:59:05 db-master-prod-b mysqld: 	version    = 3,
Mar 17 03:59:05 db-master-prod-b mysqld: 	component  = PRIMARY,
Mar 17 03:59:05 db-master-prod-b mysqld: 	conf_id    = 207,
Mar 17 03:59:05 db-master-prod-b mysqld: 	members    = 2/3 (joined/total),
Mar 17 03:59:05 db-master-prod-b mysqld: 	act_id     = 2879312,
Mar 17 03:59:05 db-master-prod-b mysqld: 	last_appl. = -1,
Mar 17 03:59:05 db-master-prod-b mysqld: 	protocols  = 0/7/3 (gcs/repl/appl),
Mar 17 03:59:05 db-master-prod-b mysqld: 	group UUID = a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Flow-control interval: [28, 28]
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 2879312)
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: State transfer required: 
Mar 17 03:59:05 db-master-prod-b mysqld: 	Group state: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2879312
Mar 17 03:59:05 db-master-prod-b mysqld: 	Local state: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2879285
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: New cluster view: global state: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2879312, view# 208: Primary, number of nodes: 3, my index: 0, protocol version 3
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Warning] WSREP: Gap in state sequence. Need state transfer.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '10.240.115.41' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --defaults-group-suffix '' --parent '21511' --binlog '/var/log/mysql/mariadb-bin' '
Mar 17 03:59:05 db-master-prod-b rsyncd[21554]: rsyncd version 3.0.9 starting, listening on port 4444
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Prepared SST request: rsync|10.240.115.41:4444/rsync_sst
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: REPL Protocols: 7 (3, 2)
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Service thread queue flushed.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Assign initial position for certification: 2879312, protocol version: 3
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Service thread queue flushed.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Prepared IST receiver, listening at: tcp://10.240.115.41:4568
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Member 0.0 (db-master-prod-b) requested state transfer from '*any*'. Selected 2.0 (db-master-prod-a)(SYNCED) as donor.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 2879312)
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Requesting state transfer: success, donor: 2
Mar 17 03:59:05 db-master-prod-b rsyncd[21570]: connect from db-master-prod-a.c.rapid-depot-817.internal (10.240.173.81)
Mar 17 03:59:05 db-master-prod-b rsyncd[21570]: rsync to rsync_sst/ from db-master-prod-a.c.rapid-depot-817.internal (10.240.173.81)
Mar 17 03:59:05 db-master-prod-b rsyncd[21570]: receiving file list
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: 2.0 (db-master-prod-a): State transfer to 0.0 (db-master-prod-b) complete.
Mar 17 03:59:05 db-master-prod-b mysqld: 160317  3:59:05 [Note] WSREP: Member 2.0 (db-master-prod-a) synced with group.
Mar 17 03:59:05 db-master-prod-b rsyncd[21570]: sent 54 bytes  received 180 bytes  total size 45
Mar 17 03:59:06 db-master-prod-b mysqld: WSREP_SST: [INFO] Joiner cleanup. rsync PID: 21554 (20160317 03:59:06.678)
Mar 17 03:59:07 db-master-prod-b rsyncd[21554]: rsync error: received SIGINT, SIGTERM, or SIGHUP (code 20) at rsync.c(549) [Receiver=3.0.9]
Mar 17 03:59:07 db-master-prod-b mysqld: WSREP_SST: [INFO] Joiner cleanup done. (20160317 03:59:07.183)
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] WSREP: SST complete, seqno: 2879285
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: Using mutexes to ref count buffer pool pages
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: The InnoDB memory heap is disabled
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: Memory barrier is not used
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: Compressed tables use zlib 1.2.7
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: Using Linux native AIO
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: Using CPU crc32 instructions
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: Initializing buffer pool, size = 10.0G
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: Completed initialization of buffer pool
Mar 17 03:59:07 db-master-prod-b mysqld: 160317  3:59:07 [Note] InnoDB: Highest supported file format is Barracuda.
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] InnoDB: 128 rollback segment(s) are active.
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] InnoDB: Waiting for purge to start
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 9010595911
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] Plugin 'FEEDBACK' is disabled.
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] Server socket created on IP: '0.0.0.0'.
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [ERROR] mysqld: Table './mysql/event' is marked as crashed and should be repaired
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [ERROR] mysqld: Table 'event' is marked as crashed and should be repaired
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Warning] Checking table:   './mysql/event'
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [ERROR] mysql.event: 1 client is using or hasn't closed the table properly
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: Signalling provider to continue.
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: SST received: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2879285
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: Receiving IST: 27 writesets, seqnos 2879285-2879312
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] Event Scheduler: scheduler thread started with id 4
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] Reading of all Master_info entries succeded
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] Added new Master_info '' to hash table
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--log-basename=#' or '--relay-log=mysqld-relay-bin' to avoid this problem.
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] /usr/sbin/mysqld: ready for connections.
Mar 17 03:59:08 db-master-prod-b mysqld: Version: '10.0.22-MariaDB-1~wheezy-wsrep-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution, wsrep_25.11.r21a2415
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: (4a110c69, 'tcp://0.0.0.0:4567') turning message relay requesting off
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: IST received: a54b1cb6-dd60-11e4-9e2f-fa9dc559c84a:2879312
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: 0.0 (db-master-prod-b): State transfer from 2.0 (db-master-prod-a) complete.
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: Shifting JOINER -> JOINED (TO: 2879312)
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: Member 0.0 (db-master-prod-b) synced with group.
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 2879312)
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: Synchronized with group, ready for connections
Mar 17 03:59:08 db-master-prod-b mysqld: 160317  3:59:08 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Mar 17 03:59:09 db-master-prod-b /etc/mysql/debian-start[21812]: Upgrading MySQL tables if necessary.
Mar 17 03:59:09 db-master-prod-b /etc/mysql/debian-start[21817]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored
Mar 17 03:59:09 db-master-prod-b /etc/mysql/debian-start[21817]: Looking for 'mysql' as: /usr/bin/mysql
Mar 17 03:59:09 db-master-prod-b /etc/mysql/debian-start[21817]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Mar 17 03:59:09 db-master-prod-b /etc/mysql/debian-start[21817]: This installation of MySQL is already upgraded to 10.0.22-MariaDB, use --force if you still need to run mysql_upgrade
Mar 17 03:59:09 db-master-prod-b /etc/mysql/debian-start[21827]: Checking for insecure root accounts.
Mar 17 03:59:09 db-master-prod-b /etc/mysql/debian-start[21831]: Triggering myisam-recover for all MyISAM tables
Mar 17 03:59:12 db-master-prod-b mysqld: 160317  3:59:12 [Warning] IP address '10.168.2.4' could not be resolved: Name or service not known
Mar 17 03:59:13 db-master-prod-b mysqld: 160317  3:59:13 [Warning] IP address '10.168.0.2' could not be resolved: Name or service not known
Mar 17 03:59:16 db-master-prod-b mysqld: 160317  3:59:16 [Warning] IP address '10.168.1.5' could not be resolved: Name or service not known
Mar 17 03:59:16 db-master-prod-b mysqld: 160317  3:59:16 [Note] Start binlog_dump to slave_server(400), pos(mariadb-bin.000406, 4)

Comment by Robin Anil [ 2016-03-17 ]

Elena, here is our my.cnf. Let us know if there is anything we can provide. Unfortunately the data is sensitive and we cannot share it.

[client]
port		= 3306
socket		= /var/run/mysqld/mysqld.sock
 
# Here is entries for some specific programs
# The following values assume you have at least 32M ram
 
# This was formally known as [safe_mysqld]. Both versions are currently parsed.
[mysqld_safe]
socket		= /var/run/mysqld/mysqld.sock
nice		= 0
 
[mysqld]
#
# * Basic Settings
#
user		= mysql
pid-file	= /var/run/mysqld/mysqld.pid
socket		= /var/run/mysqld/mysqld.sock
port		= 3306
basedir		= /usr
datadir		= /var/lib/mysql
tmpdir		= /tmp
lc_messages_dir	= /usr/share/mysql
lc_messages	= en_US
skip-external-locking
#
# Instead of skip-networking the default is now to listen only on
# localhost which is more compatible and is not less secure.
bind-address		= 0.0.0.0
#
# * Fine Tuning
#
max_connections		= 1000
connect_timeout		= 5
wait_timeout		= 600
max_allowed_packet	= 16M
thread_cache_size       = 128
sort_buffer_size	= 16M
bulk_insert_buffer_size	= 16M
tmp_table_size		= 256M
max_heap_table_size	= 256M
#
# * MyISAM
#
# This replaces the startup script and checks MyISAM tables if needed
# the first time they are touched. On error, make copy and try a repair.
myisam_recover          = BACKUP
key_buffer_size		= 128M
#open-files-limit	= 2000
table_open_cache	= 400
myisam_sort_buffer_size	= 512M
concurrent_insert	= 2
read_buffer_size	= 2M
read_rnd_buffer_size	= 1M
#
# * Query Cache Configuration
#
# Cache only tiny result sets, so we can fit more in the query cache.
query_cache_limit		= 128K
query_cache_size		= 64M
# for more write intensive setups, set to DEMAND or OFF
query_cache_type		= ON
#
# * Logging and Replication
#
# Both location gets rotated by the cronjob.
# Be aware that this log type is a performance killer.
# As of 5.1 you can enable the log at runtime!
#general_log_file        = /var/log/mysql/mysql.log
#general_log             = 1
#
# Error logging goes to syslog due to /etc/mysql/conf.d/mysqld_safe_syslog.cnf.
#
# we do want to know about network errors and such
log_warnings		= 2
#
# Enable the slow query log to see queries with especially long duration
slow_query_log=1
slow_query_log_file	= /var/log/mysql/mariadb-slow.log
long_query_time = 1
#log_slow_rate_limit	= 1000
log_slow_verbosity	= query_plan
 
#log-queries-not-using-indexes
#log_slow_admin_statements
#
# The following can be used as easy to replay backup logs or for replication.
# note: if you are setting up a replication slave, see README.Debian about
#       other settings you may need to change.
server-id		= 200
#report_host		= master1
#auto_increment_increment = 2
#auto_increment_offset	= 1
log_bin			= /var/log/mysql/mariadb-bin
log_bin_index		= /var/log/mysql/mariadb-bin.index
# not fab for performance, but safer
#sync_binlog		= 1
expire_logs_days	= 10
max_binlog_size         = 100M
# slaves
#relay_log		= /var/log/mysql/relay-bin
#relay_log_index	= /var/log/mysql/relay-bin.index
#relay_log_info_file	= /var/log/mysql/relay-bin.info
#log_slave_updates
#read_only
#
# If applications support it, this stricter sql_mode prevents some
# mistakes like inserting invalid dates etc.
#sql_mode		= NO_ENGINE_SUBSTITUTION,TRADITIONAL
#
# * InnoDB
#
# InnoDB is enabled by default with a 10MB datafile in /var/lib/mysql/.
# Read the manual for more InnoDB related options. There are many!
event_scheduler=ON
default_storage_engine	= InnoDB
# you can't just change log file size, requires special procedure
innodb_log_file_size	= 512M
innodb_buffer_pool_size	= 10G
innodb_log_buffer_size	= 8M
innodb_file_per_table	= 1
innodb_open_files	= 400
innodb_io_capacity	= 10000
innodb_flush_method	= O_DIRECT
innodb_flush_log_at_trx_commit=2
innodb_change_buffer_max_size = 25
innodb_read_io_threads = 64
innodb_thread_concurrency = 16
innodb_write_io_threads = 64
 
log_slave_updates=1
binlog_format=ROW
 
#
# * Security Features
#
# Read the manual, too, if you want chroot!
# chroot = /var/lib/mysql/
#
# For generating SSL certificates I recommend the OpenSSL GUI "tinyca".
#
# ssl-ca=/etc/mysql/cacert.pem
# ssl-cert=/etc/mysql/server-cert.pem
# ssl-key=/etc/mysql/server-key.pem
 
 
 
[mysqldump]
quick
quote-names
max_allowed_packet	= 16M
 
[mysql]
#no-auto-rehash	# faster start of mysql but no tab completition
 
[isamchk]
key_buffer		= 16M
 
#
# * IMPORTANT: Additional settings that can override those from this file!
#   The files must end with '.cnf', otherwise they'll be ignored.
#
!includedir /etc/mysql/conf.d/

Comment by Aaron Zimmerman [ 2016-04-15 ]

Another crash.

Apr 15 02:19:39 db-master-prod-b mysqld: 160415 2:19:39 [Warning] Aborted connection 601114 to db: 'tock_events_prod' user: 'tock_prod2' host: '10.204.1.5' (Unknown error)
Apr 15 02:23:21 db-master-prod-b mysqld: 2016-04-15 02:23:21 7f6d6f8db700 InnoDB: Assertion failure in thread 140107999721216 in file lock0lock.cc line 2031
Apr 15 02:23:21 db-master-prod-b mysqld: InnoDB: We intentionally generate a memory trap.
Apr 15 02:23:21 db-master-prod-b mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Apr 15 02:23:21 db-master-prod-b mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Apr 15 02:23:21 db-master-prod-b mysqld: InnoDB: immediately after the mysqld startup, there may be
Apr 15 02:23:21 db-master-prod-b mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Apr 15 02:23:21 db-master-prod-b mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Apr 15 02:23:21 db-master-prod-b mysqld: InnoDB: about forcing recovery.
Apr 15 02:23:21 db-master-prod-b mysqld: 160415 2:23:21 [ERROR] mysqld got signal 6 ;
Apr 15 02:23:21 db-master-prod-b mysqld: This could be because you hit a bug. It is also possible that this binary
Apr 15 02:23:21 db-master-prod-b mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Apr 15 02:23:21 db-master-prod-b mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Apr 15 02:23:21 db-master-prod-b mysqld:
Apr 15 02:23:21 db-master-prod-b mysqld: To report this bug, see http://kb.askmonty.org/en/reporting-bugs
Apr 15 02:23:21 db-master-prod-b mysqld:
Apr 15 02:23:21 db-master-prod-b mysqld: We will try our best to scrape up some info that will hopefully help
Apr 15 02:23:21 db-master-prod-b mysqld: diagnose the problem, but since we have already crashed,
Apr 15 02:23:21 db-master-prod-b mysqld: something is definitely wrong and this may fail.
Apr 15 02:23:21 db-master-prod-b mysqld:
Apr 15 02:23:21 db-master-prod-b mysqld: Server version: 10.0.24-MariaDB-1~wheezy-wsrep
Apr 15 02:23:21 db-master-prod-b mysqld: key_buffer_size=134217728
Apr 15 02:23:21 db-master-prod-b mysqld: read_buffer_size=2097152
Apr 15 02:23:21 db-master-prod-b mysqld: max_used_connections=104
Apr 15 02:23:21 db-master-prod-b mysqld: max_threads=1002
Apr 15 02:23:21 db-master-prod-b mysqld: thread_count=58
Apr 15 02:23:21 db-master-prod-b mysqld: It is possible that mysqld could use up to
Apr 15 02:23:21 db-master-prod-b mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18620167 K bytes of memory
Apr 15 02:23:21 db-master-prod-b mysqld: Hope that's ok; if not, decrease some variables in the equation.
Apr 15 02:23:21 db-master-prod-b mysqld:
Apr 15 02:23:21 db-master-prod-b mysqld: Thread pointer: 0x0x7f6d089f3008
Apr 15 02:23:21 db-master-prod-b mysqld: Attempting backtrace. You can use the following information to find out
Apr 15 02:23:21 db-master-prod-b mysqld: where mysqld died. If you see no messages after this, something went
Apr 15 02:23:21 db-master-prod-b mysqld: terribly wrong...
Apr 15 02:23:21 db-master-prod-b mysqld: stack_bottom = 0x7f6d6f8dad5f thread_stack 0x48000
Apr 15 02:23:21 db-master-prod-b mysqld: Fatal signal 11 while backtracing
Apr 15 02:23:26 db-master-prod-b mysqld_safe: Number of processes running now: 0
Apr 15 02:23:26 db-master-prod-b mysqld_safe: WSREP: not restarting wsrep node automatically
Apr 15 02:23:26 db-master-prod-b mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
Apr 15 02:24:00 db-master-prod-b collectd[28255]: mysql plugin: Lost connection to instance "tock_prod": MySQL server has gone away
Apr 15 02:24:00 db-master-prod-b collectd[28255]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Apr 15 02:24:00 db-master-prod-b collectd[28255]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 120.000 seconds.
Apr 15 02:26:00 db-master-prod-b collectd[28255]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Apr 15 02:26:00 db-master-prod-b collectd[28255]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 240.000 seconds.
Apr 15 02:30:00 db-master-prod-b collectd[28255]: mysql plugin: Failed to connect to database <none> at server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")
Apr 15 02:30:00 db-master-prod-b collectd[28255]: read-function of plugin `mysql-tock_prod' failed. Will suspend it for 480.000 seconds.

Comment by Elena Stepanova [ 2020-10-20 ]

10.0 version has gone EOL some time ago.

We have never been able to reproduce the assertion failure InnoDB: Failing assertion: trx->lock.n_active_thrs == 1 mentioned in the comments (we had a similar assertion fixed in MDEV-14633, but it was about system versioning which was only introduced in 10.3, so can't be the same). There is also an open bug report MDEV-15972 which also mentions this assertion failure, in 10.2.

Other stack traces in this issue are too non-distinctive to be meaningfully matched with any existing or fixed bugs.

Thus closing. If it so happens that new information concerning active server version arrives, the issue can be re-opened.

Generated at Thu Feb 08 07:30:24 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.