Bug #90573 MySQL crash
Submitted: 23 Apr 2018 13:14 Modified: 9 Oct 2018 16:07
Reporter: Alexey Koscheev Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:5.6.40 OS:FreeBSD (11.1)
Assigned to: CPU Architecture:Other (amd64)

[23 Apr 2018 13:14] Alexey Koscheev
Description:
Mysql server craches on SQL-query:

SELECT SQL_NO_CACHE m.type_alias, m.content_item_id, m.core_content_id, count(m.tag_id) AS match_count, MAX(m.tag_date) as tag_date, MAX(c.core_title) AS core_title, MAX(c.core_params) AS core_params,MAX(c.core_alias) AS core_alias, MAX(c.core_body) AS core_body, MAX(c.core_state) AS core_state, MAX(c.core_access) AS core_access,MAX(c.core_metadata) AS core_metadata, MAX(c.core_created_user_id) AS core_created_user_id, MAX(c.core_created_by_alias) AS core_created_by_alias,MAX(c.core_created_time) as core_created_time, MAX(c.core_images) as core_images,CASE WHEN c.core_modified_time = '0000-00-00 00:00:00' THEN c.core_created_time ELSE c.core_modified_time END as core_modified_time,MAX(c.core_language) AS core_language, MAX(c.core_catid) AS core_catid,MAX(c.core_publish_up) AS core_publish_up, MAX(c.core_publish_down) as core_publish_down,MAX(ct.type_title) AS content_type_title, MAX(ct.router) AS router,CASE WHEN c.core_created_by_alias > ' ' THEN c.core_created_by_alias ELSE ua.name END AS author,ua.email AS author_email
FROM vm3jo_contentitem_tag_map AS m
INNER JOIN vm3jo_ucm_content AS c ON m.type_alias = c.core_type_alias AND m.core_content_id = c.core_content_id AND c.core_state IN (1) AND (c.core_publish_up = '0000-00-00 00:00:00' OR c.core_publish_up <= '2018-04-23 11:43:45')  AND (c.core_publish_down = '0000-00-00 00:00:00' OR  c.core_publish_down >= '2018-04-23 11:43:45')
INNER JOIN vm3jo_content_types AS ct ON ct.type_alias = m.type_alias
INNER JOIN vm3jo_categories AS tc ON tc.id = c.core_catid AND tc.published = 1
LEFT JOIN vm3jo_users AS ua ON ua.id = c.core_created_user_id
WHERE m.tag_id IN (9) AND m.type_alias IN ('com_content.article','com_contact.contact','com_newsfeeds.newsfeed','com_users.user','com_content.category','com_contact.category','com_newsfeeds.category','com_tags.tag','com_banners.banner','com_banners.category','com_banners.client','com_users.note','com_users.category') AND c.core_access IN (0,1,5)
GROUP BY m.type_alias, m.content_item_id, m.core_content_id, core_modified_time, core_created_time, core_created_by_alias, name, author_email
ORDER BY MAX(`c`.`core_publish_up`) DESC;

In error log:

2018-04-23 15:58:36 24729 [ERROR] /usr/local/libexec/mysqld: Incorrect key file for table '/var/tmpmysql/#sql6099_7_7.MYI'; try to repair it
2018-04-23 15:58:36 24729 [ERROR] /usr/local/libexec/mysqld: Sort aborted: Incorrect key file for table '/var/tmpmysql/#sql6099_7_7.MYI'; try to repair it
2018-04-23 15:58:36 24729 [ERROR] /usr/local/libexec/mysqld: Incorrect key file for table '/var/tmpmysql/#sql6099_7_8.MYI'; try to repair it
2018-04-23 15:58:36 24729 [ERROR] /usr/local/libexec/mysqld: Sort aborted: Incorrect key file for table '/var/tmpmysql/#sql6099_7_8.MYI'; try to repair it
2018-04-23 15:58:36 24729 [ERROR] /usr/local/libexec/mysqld: Incorrect key file for table '/var/tmpmysql/#sql6099_7_9.MYI'; try to repair it
2018-04-23 15:58:36 24729 [ERROR] /usr/local/libexec/mysqld: Sort aborted: Incorrect key file for table '/var/tmpmysql/#sql6099_7_9.MYI'; try to repair it
2018-04-23 15:58:57 24729 [ERROR] /usr/local/libexec/mysqld: Incorrect key file for table '/var/tmpmysql/#sql6099_8_0.MYI'; try to repair it
2018-04-23 15:58:57 24729 [ERROR] /usr/local/libexec/mysqld: Sort aborted: Incorrect key file for table '/var/tmpmysql/#sql6099_8_0.MYI'; try to repair it
2018-04-23 15:58:57 24729 [ERROR] /usr/local/libexec/mysqld: Incorrect key file for table '/var/tmpmysql/#sql6099_8_1.MYI'; try to repair it
2018-04-23 15:58:57 24729 [ERROR] /usr/local/libexec/mysqld: Sort aborted: Incorrect key file for table '/var/tmpmysql/#sql6099_8_1.MYI'; try to repair it
12:58:58 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.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.

key_buffer_size=52428800
read_buffer_size=8388608
max_used_connections=1
max_threads=200
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 3330523 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x814e32800
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 = 7fffdd7a7f50 thread_stack 0x40000
0x971007 <my_print_stacktrace+0x27> at /usr/local/libexec/mysqld
0x680cc9 <handle_fatal_signal+0x2b9> at /usr/local/libexec/mysqld
0x802b6a926 <pthread_sigmask+0x536> at /lib/libthr.so.3
0x802b69ecf <pthread_getspecific+0xe5f> at /lib/libthr.so.3

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (81564e010): SELECT m.type_alias, m.content_item_id, m.core_content_id, count(m.tag_id) AS match_count, MAX(m.tag_date) as tag_date, MAX(c.core_title)
AS core_title, MAX(c.core_params) AS core_params,MAX(c.core_alias) AS core_alias, MAX(c.core_body) AS core_body, MAX(c.core_state) AS core_state, MAX(c.core_
access) AS core_access,MAX(c.core_metadata) AS core_metadata, MAX(c.core_created_user_id) AS core_created_user_id, MAX(c.core_created_by_alias) AS core_creat
ed_by_alias,MAX(c.core_created_time) as core_created_time, MAX(c.core_images) as core_images,CASE WHEN c.core_modified_time = '0000-00-00 00:00:00' THEN c.co
re_created_time ELSE c.core_modified_time END as core_modified_time,MAX(c.core_language) AS core_language, MAX(c.core_catid) AS core_catid,MAX(c.core_publish
_up) AS core_publish_up, MAX(c.core_publish_down) as core_publish_down,MAX(ct.type_title) AS content_type_title, MAX(ct.router) AS router,CASE WHEN c.core_cr
eated_by_alias > ' ' THEN c.core_created_by_alias ELSE ua.name END AS author,ua.email AS author_email
Connection ID (thread ID): 9
Status: NOT_KILLED

Recompiling with -DWITH_DEBUG=1 do not provide additional info in log.

All tables in InnoDB.

More frequently this query add to log
/usr/local/libexec/mysqld: Sort aborted: Incorrect key file for table '/var/tmpmysql/#sql6099_7_8.MYI'; try to repair it
and sometimes MySQL server crashes.

Database is about 90 Mb, sql dump 38 Mb.

How to repeat:
Don't know how to repeat without sql-dump.
[23 Apr 2018 13:15] Alexey Koscheev
There is no problem with this database with MySQL 5.7.21.
[23 Apr 2018 13:26] Alexey Koscheev
show create table

Attachment: tables.txt (text/plain), 7.98 KiB.

[23 Apr 2018 14:23] Alexey Koscheev
gdb /usr/local/libexec/mysqld
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "amd64-marcel-freebsd"...(no debugging symbols found)...
(gdb) set args --defaults-extra-file=/usr/local/etc/mysql/my.cnf --basedir=/usr/local --datadir=/var/db/mysql --plugin-dir=/usr/local/lib/mysql/plugin --log-error=freebsd11.build.ihead.ru.err --pid-file=/var/db/mysql/freebsd11.build.ihead.ru.pid --socket=/tmp/mysql.sock --port=13306
(gdb) run
Starting program: /usr/local/libexec/mysqld --defaults-extra-file=/usr/local/etc/mysql/my.cnf --basedir=/usr/local --datadir=/var/db/mysql --plugin-dir=/usr/local/lib/mysql/plugin --log-error=freebsd11.build.ihead.ru.err --pid-file=/var/db/mysql/freebsd11.build.ihead.ru.pid --socket=/tmp/mysql.sock --port=13306
(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...(no debugging symbols found)...2018-04-23 17:21:08 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2018-04-23 17:21:08 0 [Note] /usr/local/libexec/mysqld (mysqld 5.6.40-debug-log) starting as process 34743 ...

Program received signal SIGSEGV, Segmentation fault.
0x0000000802edc196 in memcpy () from /lib/libc.so.7
(gdb) backtrace full
#0  0x0000000802edc196 in memcpy () from /lib/libc.so.7
No symbol table info available.
#1  0x0000000000bea9ba in _mi_get_pack_key ()
No symbol table info available.
#2  0x0000000000be9684 in _mi_seq_search ()
No symbol table info available.
#3  0x31660b0172657355 in ?? ()
No symbol table info available.
#4  0x722e6b62406d6f74 in ?? ()
No symbol table info available.
#5  0x131c6a0200000075 in ?? ()
No symbol table info available.
#6  0x746e6f635f6d6f63 in ?? ()
No symbol table info available.
#7  0x697472612e746e65 in ?? ()
No symbol table info available.
#8  0x00a4000000656c63 in ?? ()
No symbol table info available.
#9  0x7075530a01650000 in ?? ()
No symbol table info available.
#10 0x0172657355207265 in ?? ()
No symbol table info available.
#11 0x62406d6f7431660b in ?? ()
No symbol table info available.
#12 0x0200000075722e6b in ?? ()
No symbol table info available.
#13 0x635f6d6f63139872 in ?? ()
No symbol table info available.
#14 0x612e746e65746e6f in ?? ()
No symbol table info available.
#15 0x0000656c63697472 in ?? ()
No symbol table info available.
#16 0x0a0169000000a800 in ?? ()
No symbol table info available.
#17 0x7355207265707553 in ?? ()
No symbol table info available.
#18 0x6f7431660b017265 in ?? ()
No symbol table info available.
#19 0x0075722e6b62406d in ?? ()
No symbol table info available.
#20 0x6f6313647a020000 in ?? ()
No symbol table info available.
#21 0x6e65746e6f635f6d in ?? ()
No symbol table info available.
#22 0x6c63697472612e74 in ?? ()
No symbol table info available.
#23 0x000000a900000065 in ?? ()
No symbol table info available.
#24 0x72657075530a016a in ?? ()
No symbol table info available.
#25 0x660b017265735520 in ?? ()
No symbol table info available.
#26 0x2e6b62406d6f7431 in ?? ()
No symbol table info available.
#27 0xc084020000007572 in ?? ()
No symbol table info available.
#28 0x6e6f635f6d6f6313 in ?? ()
No symbol table info available.
[28 Apr 2018 12:19] Alexey Koscheev
Problem repeated on another server.

It is not tmpdir's size issue.
[28 Apr 2018 18:12] Alexey Koscheev
Problem also present in MySQL Server 5.7.21 with internal_tmp_disk_storage_engine=MYISAM (default is INNODB).

There is no workaround for MySQL Server 5.6.40.
[28 Apr 2018 18:21] Alexey Koscheev
EXPLAIN SELECT ...

Attachment: explain.txt (text/plain), 1.74 KiB.

[12 May 2018 8:48] MySQL Verification Team
Hi Alexey,

We either need a proper stack trace,  or a mysqldump of the tables to be able to repeat a crash here.   FWIW, I tried with random data already, but not hitting any crash after a while.  Random data is a bit hard to generate for many joins and conditions.
[12 May 2018 9:04] Alexey Koscheev
Hi!

How can i get proper stack trace?
I tried different compile options but no success.

I try to prepare sql-dump with problem tables in two days.
[12 May 2018 18:14] Alexey Koscheev
I uploaded the file visible only for developers.
[12 May 2018 18:40] MySQL Verification Team
Can you make sure /var/tmpmysql/ is not running out of disk space?
And upload the my.cnf here too..  Thanks!
[12 May 2018 19:30] Alexey Koscheev
We originally use /var/tmpmysql with tmpfs, but for test purpose it is simple directory on the disk.

Problem exists regardless of tmpfs used or not. It is enough space on disk.
[13 May 2018 9:27] MySQL Verification Team
I didn't get any problems Windows or Linux.  On FreeBSD 11 on 5.7.22 I got these errors:

DBD::mysql::st execute failed: Incorrect key file for table '/var/db/mysql_tmpdir/#sql13463_6_32e.MYI'; try to repair it at bug.pl line 49.
DBD::mysql::st execute failed: Incorrect key file for table '/var/db/mysql_tmpdir/#sql13463_6_32f.MYI'; try to repair it at bug.pl line 49.
DBD::mysql::st execute failed: Incorrect key file for table '/var/db/mysql_tmpdir/#sql13463_6_330.MYI'; try to repair it at bug.pl line 49.
DBD::mysql::st execute failed: Incorrect key file for table '/var/db/mysql_tmpdir/#sql13463_6_331.MYI'; try to repair it at bug.pl line 49.
DBD::mysql::st execute failed: Incorrect key file for table '/var/db/mysql_tmpdir/#sql13463_6_332.MYI'; try to repair it at bug.pl line 49.

But no crash (yet).   I'll look into it more...
[13 May 2018 15:00] Alexey Koscheev
Yes it is difficult to reproduce only with this script.

It is easier reproducible when other queries executed in this database (like joomla does).

Anyway, "Incorrect key file for table '/var/db/mysql_tmpdir/#sql13463_6_32f.MYI'; try to repair it" - says that something goes wrong.

If we fix it, most likely, we also fix a crash.
[14 May 2018 9:19] MySQL Verification Team
Now I built mysqld 5.7.22 from source and can no longer repeat the issue.
I repeated it only with the one installed by "pkg install mysql57-server"

Upon searching,  I found this:
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=219238

It needs somebody with an account to update it saying test 5.7 with
internal_tmp_disk_storage_engine=MyISAM
[14 May 2018 9:37] MySQL Verification Team
So I've tried using Oracle/MySQL binaries, in particular the mysql-5.7.22-freebsd11-x86_64.tar.gz from dev.mysql.com and see no problems.

Also our binaries are not stripped.  So you may get a better stack trace.
Please try it.
[14 May 2018 17:37] Alexey Koscheev
Hi!

Originally i reported about the problem with version 5.6 because it is default version on all our servers and there is no workaround for this version.

I tried mysql-server56 from pkg repository and also build it via Freebsd ports.

I did not tried compile it another way.

I updated https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=219238