Ver 5.7.17-12 for Linux on x86_64 (Percona Server (GPL), Release 12, Revision 1e87281)
Slave host was configured with the semi-sync replication plugin, but slave had stopped because while the master had it's mysql.time_zone_name tables populated, the slave did not and it couldn't interpret UTC:
mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 10.1.3.62
Master_User: repluser
Master_Port: 3310
Connect_Retry: 60
Master_Log_File: mysql-bin.000001
Read_Master_Log_Pos: 165192
Relay_Log_File: dev-db-006-relay-bin.000002
Relay_Log_Pos: 41019
Relay_Master_Log_File: mysql-bin.000001
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 1298
Last_Error: Error 'Unknown or incorrect time zone: 'UTC'' on query. Default database: 'user_identity'. Query: 'BEGIN'
Skip_Counter: 0
Exec_Master_Log_Pos: 41059
Relay_Log_Space: 165364
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 1298
Last_SQL_Error: Error 'Unknown or incorrect time zone: 'UTC'' on query. Default database: 'user_identity'. Query: 'BEGIN'
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1291
Master_UUID: 049c8974-6ef0-11e6-8d8c-005056a43b3b
Master_Info_File: /var/lib/mysql/dev100/data/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State:
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp: 170404 10:19:29
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set: 049c8974-6ef0-11e6-8d8c-005056a43b3b:2-18
Executed_Gtid_Set: 049c8974-6ef0-11e6-8d8c-005056a43b3b:1-4
Auto_Position: 1
Replicate_Rewrite_DB:
Channel_Name:
Master_TLS_Version:
1 row in set (0.00 sec)
Followed the steps here to populate the mysql schema's time zone tables: https://dev.mysql.com/doc/refman/5.7/en/mysql-tzinfo-to-sql.html
Then issued start slave:
mysql> start slave;
Query OK, 0 rows affected (0.01 sec)
mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 10.1.3.62
Master_User: repluser
Master_Port: 3310
Connect_Retry: 60
Master_Log_File: mysql-bin.000001
Read_Master_Log_Pos: 165192
Relay_Log_File: dev-db-006-relay-bin.000002
Relay_Log_Pos: 165152
Relay_Master_Log_File: mysql-bin.000001
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 165192
Relay_Log_Space: 165364
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1291
Master_UUID: 049c8974-6ef0-11e6-8d8c-005056a43b3b
Master_Info_File: /var/lib/mysql/dev100/data/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp:
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set: 049c8974-6ef0-11e6-8d8c-005056a43b3b:2-18
Executed_Gtid_Set: 049c8974-6ef0-11e6-8d8c-005056a43b3b:1-18,
1b243eee-18a9-11e7-9d60-005056a4de24:1-5
Auto_Position: 1
Replicate_Rewrite_DB:
Channel_Name:
Master_TLS_Version:
1 row in set (0.00 sec)
Moments later mysqld crashed. Upon auto-restart tries by systemd, mysqld continued to fail with the same message:
2017-04-06T13:02:36.743135Z 21 [Warning] Slave SQL for channel '': If a crash happens this configuration does not guarantee that the relay log info will be consistent, Error_code: 0
2017-04-06T13:02:36.749133Z 21 [Note] Slave SQL thread for channel '' initialized, starting replication in log 'mysql-bin.000001' at position 41059, relay log './dev-db-006-relay-bin.000002' position: 41019
2017-04-06 09:02:56 0x7f5e291f8700 InnoDB: Assertion failure in thread 140042393585408 in file btr0sea.cc line 1564
InnoDB: Failing assertion: index->id == btr_page_get_index_id(page)
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
13:02:56 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/
key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=152
thread_count=3
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68317 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x3b)[0xeffd8b]
/usr/sbin/mysqld(handle_fatal_signal+0x471)[0x7a0181]
/lib64/libpthread.so.0(+0xf370)[0x7f5ed4cf6370]
/lib64/libc.so.6(gsignal+0x37)[0x7f5ed2e7b1d7]
/lib64/libc.so.6(abort+0x148)[0x7f5ed2e7c8c8]
/usr/sbin/mysqld[0x76e3b8]
/usr/sbin/mysqld[0x11d1ce7]
/usr/sbin/mysqld(_Z27btr_search_info_update_slowP12btr_search_tP9btr_cur_t+0x1a4)[0x11d2074]
/usr/sbin/mysqld(_Z27btr_cur_search_to_nth_levelP12dict_index_tmPK8dtuple_t15page_cur_mode_tmP9btr_cur_tmPKcmP5mtr_t+0x2773)[0x11c3533]
/usr/sbin/mysqld(_Z29row_ins_clust_index_entry_lowmmP12dict_index_tmP8dtuple_tmP9que_thr_tb+0x252)[0x10dae32]
/usr/sbin/mysqld(_Z25row_ins_clust_index_entryP12dict_index_tP8dtuple_tP9que_thr_tmb+0xa8)[0x10dc2c8]
/usr/sbin/mysqld(_Z12row_ins_stepP9que_thr_t+0x379)[0x10dc7c9]
/usr/sbin/mysqld(_Z15que_run_threadsP9que_thr_t+0x6f9)[0x10b36b9]
/usr/sbin/mysqld(_Z12que_eval_sqlP11pars_info_tPKcmP5trx_t+0xb2)[0x10b4312]
/usr/sbin/mysqld[0x1248480]
/usr/sbin/mysqld[0x12486db]
/usr/sbin/mysqld[0x1252531]
/usr/sbin/mysqld(_Z17dict_stats_updateP12dict_table_t23dict_stats_upd_option_t+0x1368)[0x1253fb8]
/usr/sbin/mysqld(dict_stats_thread+0xa02)[0x1256472]
/lib64/libpthread.so.0(+0x7dc5)[0x7f5ed4ceedc5]
/lib64/libc.so.6(clone+0x6d)[0x7f5ed2f3d73d]
You may download the Percona Server operations manual by visiting
http://www.percona.com/software/percona-server/. You may find information
in the manual which will help you identify the cause of the crash.
2017-04-06T13:02:57.503692Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-04-06T13:02:57.506222Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.17-12-log) starting as process 16069 ...
2017-04-06T13:02:57.513198Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-04-06T13:02:57.513254Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-04-06T13:02:57.513266Z 0 [Note] InnoDB: Uses event mutexes
2017-04-06T13:02:57.513280Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-04-06T13:02:57.513290Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2017-04-06T13:02:57.513300Z 0 [Note] InnoDB: Using Linux native AIO
2017-04-06T13:02:57.513844Z 0 [Note] InnoDB: Number of pools: 1
2017-04-06T13:02:57.514077Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-04-06T13:02:57.518282Z 0 [Note] InnoDB: Initializing buffer pool, total size = 2G, instances = 8, chunk size = 128M
2017-04-06T13:02:57.610580Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-04-06T13:02:57.634150Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-04-06T13:02:57.662161Z 0 [Note] InnoDB: Recovering partial pages from the parallel doublewrite buffer at /var/lib/mysql/dev100/data/xb_doublewrite
2017-04-06T13:02:57.703916Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-04-06T13:02:57.718618Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 83600806
2017-04-06T13:02:57.718704Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 83601271
2017-04-06T13:02:57.733280Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 83601271
2017-04-06T13:02:57.746091Z 0 [Note] InnoDB: Database was not shutdown normally!
2017-04-06T13:02:57.746161Z 0 [Note] InnoDB: Starting crash recovery.
2017-04-06T13:02:59.082908Z 0 [Note] InnoDB: Created parallel doublewrite buffer at /var/lib/mysql/dev100/data/xb_doublewrite, size 31457280 bytes
2017-04-06T13:02:59.448033Z 0 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
2017-04-06T13:02:59.997055Z 0 [Note] InnoDB: Apply batch completed
2017-04-06T13:02:59.997209Z 0 [Note] InnoDB: Last MySQL binlog file position 0 3079620, file name mysql-bin.000001
2017-04-06T13:03:00.462647Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-04-06T13:03:00.462783Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-04-06T13:03:00.462940Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-04-06T13:03:00.480171Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-04-06T13:03:00.483435Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-04-06T13:03:00.483504Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-04-06T13:03:00.487250Z 0 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.7.17-12 started; log sequence number 83601271
2017-04-06T13:03:00.488856Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-04-06T13:03:00.489821Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/dev100/data/ib_buffer_pool
2017-04-06T13:03:00.578201Z 0 [Note] Recovering after a crash using /var/lib/mysql/dev100/binlog/mysql-bin
2017-04-06 09:03:00 0x7efc8bfff700 InnoDB: Assertion failure in thread 139623145666304 in file btr0sea.cc line 1564
InnoDB: Failing assertion: index->id == btr_page_get_index_id(page)
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
13:03:00 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/
key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=0
max_threads=152
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68317 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x7efc800008c0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7efc8bffecd0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x3b)[0xeffd8b]
/usr/sbin/mysqld(handle_fatal_signal+0x471)[0x7a0181]
/lib64/libpthread.so.0(+0xf370)[0x7efd34a7d370]
/lib64/libc.so.6(gsignal+0x37)[0x7efd32c021d7]
/lib64/libc.so.6(abort+0x148)[0x7efd32c038c8]
/usr/sbin/mysqld[0x76e3b8]
/usr/sbin/mysqld[0x11d1ce7]
/usr/sbin/mysqld(_Z27btr_search_info_update_slowP12btr_search_tP9btr_cur_t+0x1a4)[0x11d2074]
/usr/sbin/mysqld(_Z27btr_cur_search_to_nth_levelP12dict_index_tmPK8dtuple_t15page_cur_mode_tmP9btr_cur_tmPKcmP5mtr_t+0x2773)[0x11c3533]
/usr/sbin/mysqld(_Z21row_search_on_row_refP10btr_pcur_tmPK12dict_table_tPK8dtuple_tP5mtr_t+0xb4)[0x110a5d4]
/usr/sbin/mysqld[0x1105896]
/usr/sbin/mysqld(_Z14row_purge_stepP9que_thr_t+0x777)[0x1108257]
/usr/sbin/mysqld(_Z15que_run_threadsP9que_thr_t+0x87f)[0x10b383f]
/usr/sbin/mysqld(srv_worker_thread+0x508)[0x113ee98]
/lib64/libpthread.so.0(+0x7dc5)[0x7efd34a75dc5]
/lib64/libc.so.6(clone+0x6d)[0x7efd32cc473d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0): Connection ID (thread ID): 0
Status: NOT_KILLED
You may download the Percona Server operations manual by visiting
http://www.percona.com/software/percona-server/. You may find information
in the manual which will help you identify the cause of the crash.
Percona now uses JIRA for bug reports so this bug report is migrated to: https:/