5.7 with generated columns crashes with signal 11 Item_func4walkE in backtrace

[Maxim Fedotov]

Server version: 5.7.15-9-log Percona Server (GPL), Release '9', Revision '9f0fd0a'

uname -a
Linux devmysql-dba-vx-2 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u3 (2016-01-17) x86_64 GNU/Linux

error log:
11:28:47 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=8388608
read_buffer_size=131072
max_used_connections=201
max_threads=201
thread_count=2
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 87813 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7fc0d00749e0
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 = 7fc08a30ce80 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0xe82b4c]
/usr/sbin/mysqld(handle_fatal_signal+0x479)[0x7973b9]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf8d0)[0x7fc162ba68d0]
/usr/sbin/mysqld(_ZN9Item_func4walkEM4ItemFbPhENS0_9enum_walkES1_+0x84)[0x854594]
/usr/sbin/mysqld(_ZN9Item_func4walkEM4ItemFbPhENS0_9enum_walkES1_+0x8a)[0x85459a]
/usr/sbin/mysqld[0xcf78d9]
/usr/sbin/mysqld(_ZN5TABLE14refix_gc_itemsEP3THD+0xe3)[0xcfff93]
/usr/sbin/mysqld(_Z10open_tableP3THDP10TABLE_LISTP18Open_table_context+0x49b)[0xc003eb]
/usr/sbin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0x706)[0xc07cb6]
/usr/sbin/mysqld(_Z21open_tables_for_queryP3THDP10TABLE_LISTj+0x4a)[0xc084ba]
/usr/sbin/mysqld[0xcbc1f3]
/usr/sbin/mysqld(_Z14get_all_tablesP3THDP10TABLE_LISTP4Item+0x6ca)[0xcbca6a]
/usr/sbin/mysqld[0xca67dd]
/usr/sbin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x1a9)[0xcb8be9]
/usr/sbin/mysqld(_ZN4JOIN14prepare_resultEv+0x6d)[0xc9c49d]
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x99)[0xc2a3b9]
/usr/sbin/mysqld(_Z12handle_queryP3THDP3LEXP12Query_resultyy+0x238)[0xc9ce58]
/usr/sbin/mysqld[0x75f72d]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THDb+0x342c)[0xc5d0dc]
/usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x625)[0xc60275]
/usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x877)[0xc60b67]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x1b7)[0xc62177]
/usr/sbin/mysqld(handle_connection+0x2a0)[0xd262f0]
/usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0xe9fa44]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x80a4)[0x7fc162b9f0a4]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fc160bdf62d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7fc0d0079690): SHOW TABLE STATUS FROM `testdb` LIKE 'testtbl'
Connection ID (thread ID): 204
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.
Writing a core file
Segmentation fault (core dumped)

How to reproduce:
1. Create table with following definition (backup of database and table is in archive in attachment):

CREATE TABLE `testtbl` (
  `ID` int(11) NOT NULL AUTO_INCREMENT,
  `GUID` binary(16) NOT NULL,
  `GUIDString` varchar(36) GENERATED ALWAYS AS (lower(concat(substr(hex(`GUID`),7,2),substr(hex(`GUID`),5,2),substr(hex(`GUID`),3,2),substr(hex(`GUID`),1,2),'-',substr(hex(`GUID`),11,2),substr(hex(`GUID`),9,2),'-',substr(hex(`GUID`),15,2),substr(hex(`GUID`),13,2),'-',substr(hex(`GUID`),17,4),'-',substr(hex(`GUID`),21)))) VIRTUAL NOT NULL,
  PRIMARY KEY (`ID`),
  KEY `IX_testtbl_guid` (`GUID`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=DYNAMIC

Where GuidString converts binary GUID field into text form.

2. Run concurrent workload (i've use python script mysql.py, which is in archive in attachment)
3. Connect with mysql CLI and run select from Information_schema or from this table.
4. Percona Server will crash with signal 11

[Jericho Rivera (jericho-rivera)]

I can't reproduce this, would you be able to share your my.cnf file please.

[Maxim Fedotov (mfedotov)]

Hello, got this reproduced on different VMs.
Here is my.cnf example:

[client]
port = 3306
socket = /var/run/mysqld/mysqld.sock
host=localhost

[mysqld_safe]
socket = /var/run/mysqld/mysqld.sock
nice = 0
syslog
core-file-size=unlimited

[mysqld]
core-file
user = mysql
pid-file = /var/run/mysqld/mysqld.pid
socket = /var/run/mysqld/mysqld.sock
port = 3306
basedir = /usr
datadir = /var/lib/mysql
tmpdir = /var/lib/mysql/tmp
log_error = /var/log/mysql/error.log
max_allowed_packet = 16M
#myisam-recover-options = BACKUP
max_connections = 200
event_scheduler = 1
server-id = 49161
log_bin = /var/log/mysql/mysql-bin.log
expire_logs_days = 2
max_binlog_size = 100M
innodb_log_file_size = 256M
innodb_fast_shutdown = 0
table_open_cache = 1024
query_cache_size = 0
thread_cache_size = 20
max_heap_table_size = 50M
tmp_table_size = 50M
innodb_buffer_pool_size = 1024Mb
innodb_buffer_pool_instances = 2
join_buffer_size = 256K
explicit_defaults_for_timestamp
binlog_row_image = MINIMAL

[mysqldump]
quick
quote-names
max_allowed_packet = 16M

[mysql]
#no-auto-rehash # faster start of mysql but no tab completition

[isamchk]
#key_buffer = 16M

[Jericho Rivera (jericho-rivera)]

I got a different stack trace though:

2017-03-08T07:04:36.804061Z 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.7.15-9' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Percona Server (GPL), Release '9', Revision '9f0fd0a'
07:05:31 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=8388608
read_buffer_size=131072
max_used_connections=201
max_threads=301
thread_count=201
connection_count=201
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 127617 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f7f000555c0
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 = 7f7ec671ce40 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)[0x7f7f63564330]
/usr/sbin/mysqld(_ZN4Item17make_string_fieldEP5TABLE+0x15d)[0x8114ed]
/usr/sbin/mysqld(_ZNK4Item27numeric_context_result_typeEv+0x35)[0x7c5ba5]
/usr/sbin/mysqld(_ZN9Item_func12fix_func_argEP3THDPP4Item+0x76)[0x86a736]
/usr/sbin/mysqld(_ZN9Item_func10fix_fieldsEP3THDPP4Item+0xd7)[0x86a8a7]
/usr/sbin/mysqld(_ZN13Item_str_func10fix_fieldsEP3THDPP4Item+0x12)[0xb95412]
/usr/sbin/mysqld(_ZN9Item_func12fix_func_argEP3THDPP4Item+0xf9)[0x86a7b9]
/usr/sbin/mysqld(_ZN9Item_func10fix_fieldsEP3THDPP4Item+0xd7)[0x86a8a7]
/usr/sbin/mysqld(_ZN13Item_str_func10fix_fieldsEP3THDPP4Item+0x12)[0xb95412]
/usr/sbin/mysqld[0xd41567]
/usr/sbin/mysqld(_ZN5TABLE14refix_gc_itemsEP3THD+0xe4)[0xd49af4]
/usr/sbin/mysqld(_Z10open_tableP3THDP10TABLE_LISTP18Open_table_context+0x388)[0xc4aed8]
/usr/sbin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0x5f2)[0xc526b2]
/usr/sbin/mysqld(_Z21open_tables_for_queryP3THDP10TABLE_LISTj+0x4b)[0xc52fcb]
/usr/sbin/mysqld[0x75d7fe]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THDb+0x4375)[0xca8345]
/usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x5c5)[0xcab7c5]
/usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x92f)[0xcac17f]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x1b7)[0xcadb17]
/usr/sbin/mysqld(handle_connection+0x2a0)[0xd70c60]
/usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0x12464a4]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8184)[0x7f7f6355c184]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f7f62a6937d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f7f0005e5c0): SELECT GUID from testtbl where ID=279742
Connection ID (thread ID): 170
Status: NOT_KILLE...

[Jericho Rivera (jericho-rivera)]

Reproducible on 5.7.17 as well.

12:07:43 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=8388608
read_buffer_size=131072
max_used_connections=200
max_threads=201
thread_count=201
connection_count=200
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 87823 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f71b400e5f0
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 = 7f720852ce40 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0xecec9c]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x79f531]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10330)[0x7f726b530330]
/usr/sbin/mysqld(_ZN9Item_func4walkEM4ItemFbPhENS0_9enum_walkES1_+0x83)[0x863b53]
/usr/sbin/mysqld(_ZN9Item_func4walkEM4ItemFbPhENS0_9enum_walkES1_+0x89)[0x863b59]
/usr/sbin/mysqld[0xd47108]
/usr/sbin/mysqld(_ZN5TABLE14refix_gc_itemsEP3THD+0xe4)[0xd4f8d4]
/usr/sbin/mysqld(_Z10open_tableP3THDP10TABLE_LISTP18Open_table_context+0x388)[0xc4e6f8]
/usr/sbin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0x5f2)[0xc55f02]
/usr/sbin/mysqld(_Z21open_tables_for_queryP3THDP10TABLE_LISTj+0x4b)[0xc5681b]
/usr/sbin/mysqld[0xd09e6d]
/usr/sbin/mysqld(_Z14get_all_tablesP3THDP10TABLE_LISTP4Item+0x6e2)[0xd0a762]
/usr/sbin/mysqld[0xcf37cc]
/usr/sbin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x1e1)[0xd06591]
/usr/sbin/mysqld(_ZN4JOIN14prepare_resultEv+0x6d)[0xce960d]
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x80)[0xc79cb0]
/usr/sbin/mysqld(_Z12handle_queryP3THDP3LEXP12Query_resultyy+0x17d)[0xce9f3d]
/usr/sbin/mysqld[0x75f5a3]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THDb+0x4551)[0xcacc91]
/usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x5c5)[0xcb0185]
/usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xaba)[0xcb0cca]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x1b7)[0xcb2647]
/usr/sbin/mysqld(handle_connection+0x2a0)[0xd76ad0]
/usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0x124c234]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8184)[0x7f726b528184]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f726aa3537d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f71b40175f0): SHOW TABLE STATUS FROM `testdb` LIKE 'testtbl'
Connection ID (thread ID): 37
Status: NOT_KILLED

I had to slightly modify the python script
#await cur.execute("SELECT GUID from testtbl where ID={0};".format(random.randint(16658, 821445)))
await cur.exe...

[Jericho Rivera (jericho-rivera)]

The same crash happens on upstream mysql so I file a bug report there as well.

[Vlad Lesin (vlad-lesin)]

The bug has been already fixed in 5.7.19 with the following commit:

commit bc2ed496ad108c452370efbfd9f9962294bfecd0
Author: Sreeharsha Ramanavarapu <email address hidden>
Date: Thu Apr 27 19:00:52 2017 +0530

    Bug#25287633:GCOLS: INCORRECT BEHAVIOR WITH CHARSET CHANGES

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1069