There appears to be an intermittent hard to reproduce crash when creating SPATIAL index or inserting into a table with a SPATIAL index.
We were able to catch it at 100% success by performing a DELETE * FROM table and cancelling the delete so that an undo operation is performed and which subsequently crashes and places the server into 100% crash reproducibility loop.
Attached is the log of the start, as well as GDB session showing backtrace and local variables.
We saved the core file so please feel free to let us know if there are any particular variables you would like to examine.
2016-10-26T22:26:40.798737Z 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 65535)
2016-10-26T22:26:40.798886Z 0 [Warning] Changed limits: max_connections: 214 (requested 1000)
2016-10-26T22:26:40.798894Z 0 [Warning] Changed limits: table_open_cache: 400 (requested 2048)
2016-10-26T22:26:41.138365Z 0 [Warning] The use of InnoDB is mandatory since MySQL 5.7. The former options like '--innodb=0/1/OFF/ON' or '--skip-innodb' are ignored.
2016-10-26T22:26:41.138431Z 0 [Warning] The syntax 'avoid_temporal_upgrade' is deprecated and will be removed in a future release
2016-10-26T15:26:41.138552-08:00 0 [Warning] The use of InnoDB is mandatory since MySQL 5.7. The former options like '--innodb=0/1/OFF/ON' or '--skip-innodb' are ignored.
2016-10-26T15:26:41.138560-08:00 0 [Warning] The syntax 'avoid_temporal_upgrade' is deprecated and will be removed in a future release
2016-10-26T15:26:41.138655-08:00 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2016-10-26T15:26:41.138691-08:00 0 [Warning] 'NO_ZERO_DATE', 'NO_ZERO_IN_DATE' and 'ERROR_FOR_DIVISION_BY_ZERO' sql modes should be used with strict mode. They will be merged with strict mode in a future release.
2016-10-26T15:26:41.143780-08:00 0 [Note] /usr/sbin/mysqld (mysqld 5.7.15-9-log) starting as process 2303 ...
2016-10-26T15:26:41.198004-08:00 0 [Warning] InnoDB: Using innodb_file_format is deprecated and the parameter may be removed in future releases. See http://dev.mysql.com/doc/refman/5.7/en/innodb-file-format.html
2016-10-26T15:26:41.198163-08:00 0 [Note] InnoDB: PUNCH HOLE support available
2016-10-26T15:26:41.198214-08:00 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-10-26T15:26:41.198233-08:00 0 [Note] InnoDB: Uses event mutexes
2016-10-26T15:26:41.198249-08:00 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2016-10-26T15:26:41.198265-08:00 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
2016-10-26T15:26:41.198293-08:00 0 [Note] InnoDB: Using Linux native AIO
2016-10-26T15:26:41.199181-08:00 0 [Note] InnoDB: Number of pools: 1
2016-10-26T15:26:41.199624-08:00 0 [Note] InnoDB: Using CPU crc32 instructions
2016-10-26T15:26:41.206069-08:00 0 [Note] InnoDB: Initializing buffer pool, total size = 4.5G, instances = 4, chunk size = 128M
2016-10-26T15:26:41.708020-08:00 0 [Note] InnoDB: Completed initialization of buffer pool
2016-10-26T15:26:41.899299-08:00 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2016-10-26T15:26:41.932764-08:00 0 [Note] InnoDB: Recovering partial pages from the parallel doublewrite buffer at /vol/data-files/mysql/xb_doublewrite
2016-10-26T15:26:41.966581-08:00 0 [Note] InnoDB: Highest supported file format is Barracuda.
2016-10-26T15:26:42.111877-08:00 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 74203403885
2016-10-26T15:26:42.146248-08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74208646656
2016-10-26T15:26:42.179297-08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74213889536
2016-10-26T15:26:42.207753-08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74218373807
2016-10-26T15:26:42.357286-08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74204124672
2016-10-26T15:26:42.403936-08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74209367552
2016-10-26T15:26:42.450803-08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74214610432
2016-10-26T15:26:42.484691-08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74218373807
2016-10-26T15:26:42.484999-08:00 0 [Note] InnoDB: Database was not shutdown normally!
2016-10-26T15:26:42.485036-08:00 0 [Note] InnoDB: Starting crash recovery.
2016-10-26T15:26:43.010409-08:00 0 [Note] InnoDB: Created parallel doublewrite buffer at /vol/data-files/mysql/xb_doublewrite, size 15728640 bytes
2016-10-26T15:26:43.913424-08:00 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 92661 row operations to undo
2016-10-26T15:26:43.913493-08:00 0 [Note] InnoDB: Trx id counter is 73206528
2016-10-26T15:26:43.914279-08:00 0 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
2016-10-26T15:26:44.937905-08:00 0 [Note] InnoDB: Apply batch completed
2016-10-26T15:26:44.938012-08:00 0 [Note] InnoDB: Last MySQL binlog file position 0 5887, file name mysql-bin.000071
2016-10-26T15:26:44.975231-08:00 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions
2016-10-26T15:26:44.975294-08:00 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2016-10-26T15:26:44.975313-08:00 0 [Note] InnoDB: Rolling back trx with id 73206045, 92661 rows to undo
2016-10-26T15:26:44.975354-08:00 0 [Note] InnoDB: Creating shared tablespace for temporary tables
InnoDB: Progress in percents: 12016-10-26T15:26:44.975505-08:00 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
22:32:17 UTC - mysqld got signal 11 ;
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=33554432
read_buffer_size=131072
max_used_connections=0
max_threads=215
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 = 117962 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+0x2c)[0xec804c]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x79e2f1]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10330)[0x7ffff671c330]
/usr/sbin/mysqld(_Z26page_cur_search_with_matchPK11buf_block_tPK12dict_index_tPK8dtuple_t15page_cur_mode_tPmS9_P10page_cur_tP8rtr_info+0x1b1)[0xfe6351]
/usr/sbin/mysqld(_Z27btr_cur_search_to_nth_levelP12dict_index_tmPK8dtuple_t15page_cur_mode_tmP9btr_cur_tmPKcmP5mtr_t+0x12b9)[0x1110f79]
/usr/sbin/mysqld(_Z17rtr_pcur_open_lowP12dict_index_tmPK8dtuple_t15page_cur_mode_tmP10btr_pcur_tPKcmP5mtr_t+0xfa)[0x121b1aa]
/usr/sbin/mysqld(_Z22row_search_index_entryP12dict_index_tPK8dtuple_tmP10btr_pcur_tP5mtr_t+0x4f)[0x1059b6f]
/usr/sbin/mysqld[0x122c188]
/usr/sbin/mysqld(_Z12row_undo_modP11undo_node_tP9que_thr_t+0x55c)[0x122e80c]
/usr/sbin/mysqld(_Z13row_undo_stepP9que_thr_t+0x6c)[0x1074d2c]
/usr/sbin/mysqld(_Z15que_run_threadsP9que_thr_t+0x874)[0x1006064]
/usr/sbin/mysqld(_Z31trx_rollback_or_clean_recoveredm+0xd01)[0x10ca931]
/usr/sbin/mysqld(trx_rollback_or_clean_all_recovered+0x49)[0x10cb849]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8184)[0x7ffff6714184]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7ffff5c2137d]
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.
There appears to be an intermittent hard to reproduce crash when creating SPATIAL index or inserting into a table with a SPATIAL index.
We were able to catch it at 100% success by performing a DELETE * FROM table and cancelling the delete so that an undo operation is performed and which subsequently crashes and places the server into 100% crash reproducibility loop.
Attached is the log of the start, as well as GDB session showing backtrace and local variables.
We saved the core file so please feel free to let us know if there are any particular variables you would like to examine.
2016-10- 26T22:26: 40.798737Z 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 65535) 26T22:26: 40.798886Z 0 [Warning] Changed limits: max_connections: 214 (requested 1000) 26T22:26: 40.798894Z 0 [Warning] Changed limits: table_open_cache: 400 (requested 2048) 26T22:26: 41.138365Z 0 [Warning] The use of InnoDB is mandatory since MySQL 5.7. The former options like '--innodb= 0/1/OFF/ ON' or '--skip-innodb' are ignored. 26T22:26: 41.138431Z 0 [Warning] The syntax 'avoid_ temporal_ upgrade' is deprecated and will be removed in a future release 26T15:26: 41.138552- 08:00 0 [Warning] The use of InnoDB is mandatory since MySQL 5.7. The former options like '--innodb= 0/1/OFF/ ON' or '--skip-innodb' are ignored. 26T15:26: 41.138560- 08:00 0 [Warning] The syntax 'avoid_ temporal_ upgrade' is deprecated and will be removed in a future release 26T15:26: 41.138655- 08:00 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_ defaults_ for_timestamp server option (see documentation for more details). 26T15:26: 41.138691- 08:00 0 [Warning] 'NO_ZERO_DATE', 'NO_ZERO_IN_DATE' and 'ERROR_ FOR_DIVISION_ BY_ZERO' sql modes should be used with strict mode. They will be merged with strict mode in a future release. 26T15:26: 41.143780- 08:00 0 [Note] /usr/sbin/mysqld (mysqld 5.7.15-9-log) starting as process 2303 ... 26T15:26: 41.198004- 08:00 0 [Warning] InnoDB: Using innodb_file_format is deprecated and the parameter may be removed in future releases. See http:// dev.mysql. com/doc/ refman/ 5.7/en/ innodb- file-format. html 26T15:26: 41.198163- 08:00 0 [Note] InnoDB: PUNCH HOLE support available 26T15:26: 41.198214- 08:00 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 26T15:26: 41.198233- 08:00 0 [Note] InnoDB: Uses event mutexes 26T15:26: 41.198249- 08:00 0 [Note] InnoDB: GCC builtin __atomic_ thread_ fence() is used for memory barrier 26T15:26: 41.198265- 08:00 0 [Note] InnoDB: Compressed tables use zlib 1.2.8 26T15:26: 41.198293- 08:00 0 [Note] InnoDB: Using Linux native AIO 26T15:26: 41.199181- 08:00 0 [Note] InnoDB: Number of pools: 1 26T15:26: 41.199624- 08:00 0 [Note] InnoDB: Using CPU crc32 instructions 26T15:26: 41.206069- 08:00 0 [Note] InnoDB: Initializing buffer pool, total size = 4.5G, instances = 4, chunk size = 128M 26T15:26: 41.708020- 08:00 0 [Note] InnoDB: Completed initialization of buffer pool 26T15:26: 41.899299- 08:00 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 26T15:26: 41.932764- 08:00 0 [Note] InnoDB: Recovering partial pages from the parallel doublewrite buffer at /vol/data- files/mysql/ xb_doublewrite 26T15:26: 41.966581- 08:00 0 [Note] InnoDB: Highest supported file format is Barracuda. 26T15:26: 42.111877- 08:00 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 74203403885 26T15:26: 42.146248- 08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74208646656 26T15:26: 42.179297- 08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74213889536 26T15:26: 42.207753- 08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74218373807 26T15:26: 42.357286- 08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74204124672 26T15:26: 42.403936- 08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74209367552 26T15:26: 42.450803- 08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74214610432 26T15:26: 42.484691- 08:00 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 74218373807 26T15:26: 42.484999- 08:00 0 [Note] InnoDB: Database was not shutdown normally! 26T15:26: 42.485036- 08:00 0 [Note] InnoDB: Starting crash recovery. 26T15:26: 43.010409- 08:00 0 [Note] InnoDB: Created parallel doublewrite buffer at /vol/data- files/mysql/ xb_doublewrite, size 15728640 bytes 26T15:26: 43.913424- 08:00 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 92661 row operations to undo 26T15:26: 43.913493- 08:00 0 [Note] InnoDB: Trx id counter is 73206528 26T15:26: 43.914279- 08:00 0 [Note] InnoDB: Starting an apply batch of log records to the database... 26T15:26: 44.937905- 08:00 0 [Note] InnoDB: Apply batch completed 26T15:26: 44.938012- 08:00 0 [Note] InnoDB: Last MySQL binlog file position 0 5887, file name mysql-bin.000071 26T15:26: 44.975231- 08:00 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions 26T15:26: 44.975294- 08:00 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 26T15:26: 44.975313- 08:00 0 [Note] InnoDB: Rolling back trx with id 73206045, 92661 rows to undo 26T15:26: 44.975354- 08:00 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
InnoDB: Progress in percent: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
2016-10-
InnoDB: Progress in percents: 12016-10- 26T15:26: 44.975505- 08:00 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... bugs.percona. com/
22:32:17 UTC - mysqld got signal 11 ;
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://
key_buffer_ size=33554432 size=131072 connections= 0 size)*max_ threads = 117962 K bytes of memory
read_buffer_
max_used_
max_threads=215
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0 mysqld( my_print_ stacktrace+ 0x2c)[0xec804c] mysqld( handle_ fatal_signal+ 0x461)[ 0x79e2f1] 64-linux- gnu/libpthread. so.0(+0x10330) [0x7ffff671c330 ] mysqld( _Z26page_ cur_search_ with_matchPK11b uf_block_ tPK12dict_ index_tPK8dtupl e_t15page_ cur_mode_ tPmS9_P10page_ cur_tP8rtr_ info+0x1b1) [0xfe6351] mysqld( _Z27btr_ cur_search_ to_nth_ levelP12dict_ index_tmPK8dtup le_t15page_ cur_mode_ tmP9btr_ cur_tmPKcmP5mtr _t+0x12b9) [0x1110f79] mysqld( _Z17rtr_ pcur_open_ lowP12dict_ index_tmPK8dtup le_t15page_ cur_mode_ tmP10btr_ pcur_tPKcmP5mtr _t+0xfa) [0x121b1aa] mysqld( _Z22row_ search_ index_entryP12d ict_index_ tPK8dtuple_ tmP10btr_ pcur_tP5mtr_ t+0x4f) [0x1059b6f] mysqld[ 0x122c188] mysqld( _Z12row_ undo_modP11undo _node_tP9que_ thr_t+0x55c) [0x122e80c] mysqld( _Z13row_ undo_stepP9que_ thr_t+0x6c) [0x1074d2c] mysqld( _Z15que_ run_threadsP9qu e_thr_t+ 0x874)[ 0x1006064] mysqld( _Z31trx_ rollback_ or_clean_ recoveredm+ 0xd01)[ 0x10ca931] mysqld( trx_rollback_ or_clean_ all_recovered+ 0x49)[0x10cb849 ] 64-linux- gnu/libpthread. so.0(+0x8184) [0x7ffff6714184 ] 64-linux- gnu/libc. so.6(clone+ 0x6d)[0x7ffff5c 2137d] www.percona. com/software/ percona- server/. You may find information
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/
/usr/sbin/
/lib/x86_
/usr/sbin/
/usr/sbin/
/usr/sbin/
/usr/sbin/
/usr/sbin/
/usr/sbin/
/usr/sbin/
/usr/sbin/
/usr/sbin/
/usr/sbin/
/lib/x86_
/lib/x86_
You may download the Percona Server operations manual by visiting
http://
in the manual which will help you identify the cause of the crash.