Bug #85065 CREATE EVENT not OOM safe
Submitted: 20 Feb 2017 2:56 Modified: 2 Mar 2017 7:59
Reporter: Roel Van de Paar Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: DDL Severity:S2 (Serious)
Version:5.7.17 OS:Any
Assigned to: CPU Architecture:Any

[20 Feb 2017 2:56] Roel Van de Paar
Description:
Core was generated by `/sda/MS010217-mysql-5.7.17-linux-x86_64-debug/bin/mysqld --no-defaults --sql_mo'.
Program terminated with signal 11, Segmentation fault.
#0  0x00007fdb09603741 in __pthread_kill (threadid=<optimized out>, signo=11) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
61        val = INTERNAL_SYSCALL (tgkill, err, 3, THREAD_GETMEM (THREAD_SELF, pid),
(gdb) bt
#0  0x00007fdb09603741 in __pthread_kill (threadid=<optimized out>, signo=11) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000001826d71 in my_write_core (sig=11) at /git/mysql-server_dbg/mysys/stacktrace.c:249
#2  0x0000000000e75574 in handle_fatal_signal (sig=11) at /git/mysql-server_dbg/sql/signal_handler.cc:220
#3  <signal handler called>
#4  0x0000000001d45586 in my_valid_mbcharlen_utf8 (cs=0x2b24680 <my_charset_utf8_bin>, s=0x0, e=0x4 <Address 0x4 out of bounds>)
    at /git/mysql-server_dbg/strings/ctype-utf8.c:5883
#5  0x0000000001d455f5 in my_well_formed_len_utf8 (cs=0x2b24680 <my_charset_utf8_bin>, b=0x0, e=0x4 <Address 0x4 out of bounds>, pos=64, error=0x7fdb09bb3db8)
    at /git/mysql-server_dbg/strings/ctype-utf8.c:5944
#6  0x000000000161e331 in well_formed_copy_nchars (to_cs=0x2b24680 <my_charset_utf8_bin>, to=0x7fdac904dc32 "", to_length=192, from_cs=0x2ab49e0 <my_charset_bin>, from=0x0,
    from_length=4, nchars=64, well_formed_error_pos=0x7fdb09bb3f00, cannot_convert_error_pos=0x7fdb09bb3ef8, from_end_pos=0x7fdb09bb3ef0)
    at /git/mysql-server_dbg/sql-common/sql_string.cc:1048
#7  0x0000000000eb2e0b in field_well_formed_copy_nchars (to_cs=0x2b24680 <my_charset_utf8_bin>, to=0x7fdac904dc32 "", to_length=192, from_cs=0x2ab49e0 <my_charset_bin>,
    from=0x0, from_length=4, nchars=64, well_formed_error_pos=0x7fdb09bb3f00, cannot_convert_error_pos=0x7fdb09bb3ef8, from_end_pos=0x7fdb09bb3ef0)
    at /git/mysql-server_dbg/sql/field.cc:1294
#8  0x0000000000ec27ed in Field_string::store (this=0x7fdac903d830, from=0x0, length=4, cs=0x2ab49e0 <my_charset_bin>) at /git/mysql-server_dbg/sql/field.cc:7064
#9  0x00000000017354c5 in Event_db_repository::find_named_event (this=0x7fdafe3ff228, db=..., name=..., table=0x7fdac901c820)
    at /git/mysql-server_dbg/sql/event_db_repository.cc:1030
#10 0x0000000001735dd4 in Event_db_repository::update_timing_fields_for_event (this=0x7fdafe3ff228, thd=0x7fdacbc82000, event_db_name=..., event_name=..., last_executed=0,
    status=0) at /git/mysql-server_dbg/sql/event_db_repository.cc:1199
#11 0x0000000001739809 in Event_queue::get_top_for_execution_if_time (this=0x7fdaed275c00, thd=0x7fdacbc82000, event_name=0x7fdb09bb4d10)
    at /git/mysql-server_dbg/sql/event_queue.cc:636
#12 0x000000000173d078 in Event_scheduler::run (this=0x7fdaed275d00, thd=0x7fdacbc82000) at /git/mysql-server_dbg/sql/event_scheduler.cc:518
#13 0x000000000173c5f1 in event_scheduler_thread (arg=0x7fdacbc2e2a0) at /git/mysql-server_dbg/sql/event_scheduler.cc:243
#14 0x00000000018534f9 in pfs_spawn_thread (arg=0x7fdacbc96120) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:2188
#15 0x00007fdb095fedc5 in start_thread (arg=0x7fdb09bb5700) at pthread_create.c:308
#16 0x00007fdb07a5973d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

How to repeat:
DROP DATABASE test;CREATE DATABASE test;USE test;
update performance_schema.threads set instrumented=0;
SET @start_value=@@global.relay_log_purge;
SET @@global.event_scheduler=@start_value;
SET GLOBAL debug='+d,simulate_out_of_memory';
SELECT *;
create event root15 on schedule every '35:66' minute_second do select 1;

If you change the testcase to:

SET @@global.event_scheduler=1;
SET GLOBAL debug='+d,simulate_out_of_memory';
SELECT *;  # Gives OOM message (correct) 
CREATE EVENT root15 ON SCHEDULE EVERY '35:66' minute_second DO SELECT 1;

It crashes in a different manner:

Core was generated by `/sda/MS010217-mysql-5.7.17-linux-x86_64-debug/bin/mysqld --no-defaults --sql_mo'.
Program terminated with signal 6, Aborted.
#0  0x00007f3331c14741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
61        val = INTERNAL_SYSCALL (tgkill, err, 3, THREAD_GETMEM (THREAD_SELF, pid),
(gdb) bt
#0  0x00007f3331c14741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000001826d71 in my_write_core (sig=6) at /git/mysql-server_dbg/mysys/stacktrace.c:249
#2  0x0000000000e75574 in handle_fatal_signal (sig=6) at /git/mysql-server_dbg/sql/signal_handler.cc:220
#3  <signal handler called>
#4  0x00007f332ffa81d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007f332ffa98c8 in __GI_abort () at abort.c:90
#6  0x00007f332ffa1146 in __assert_fail_base (fmt=0x7f33300f23a8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=assertion@entry=0x1f1a5b0 "! is_set() || m_can_overwrite_status", file=file@entry=0x1f1a3b0 "/git/mysql-server_dbg/sql/sql_error.cc", line=line@entry=444,
    function=function@entry=0x1f1aac0 <Diagnostics_area::set_error_status(unsigned int, char const*, char const*)::__PRETTY_FUNCTION__> "void Diagnostics_area::set_error_status(uint, const char*, const char*)") at assert.c:92
#7  0x00007f332ffa11f2 in __GI___assert_fail (assertion=0x1f1a5b0 "! is_set() || m_can_overwrite_status", file=0x1f1a3b0 "/git/mysql-server_dbg/sql/sql_error.cc", line=444,
    function=0x1f1aac0 <Diagnostics_area::set_error_status(unsigned int, char const*, char const*)::__PRETTY_FUNCTION__> "void Diagnostics_area::set_error_status(uint, const char*, const char*)") at assert.c:101
#8  0x00000000014a821b in Diagnostics_area::set_error_status (this=0x7f32f441bd68, mysql_errno=5, message_text=0x7f3332205da0 "Out of memory (Needed 72 bytes)",
    returned_sqlstate=0x1f4dce9 "HY000") at /git/mysql-server_dbg/sql/sql_error.cc:444
#9  0x0000000001490f68 in THD::raise_condition (this=0x7f32f4419000, sql_errno=5, sqlstate=0x1f4dce9 "HY000", level=Sql_condition::SL_ERROR,
    msg=0x7f3332205da0 "Out of memory (Needed 72 bytes)", use_condition_handler=false) at /git/mysql-server_dbg/sql/sql_class.cc:1444
#10 0x0000000000e60e5f in my_message_sql (error=5, str=0x7f3332205da0 "Out of memory (Needed 72 bytes)", MyFlags=1088) at /git/mysql-server_dbg/sql/mysqld.cc:2255
#11 0x000000000181de76 in my_error (nr=5, MyFlags=1088) at /git/mysql-server_dbg/mysys/my_error.c:210
#12 0x00000000018216d8 in my_raw_malloc (size=72, my_flags=16) at /git/mysql-server_dbg/mysys/my_malloc.c:211
#13 0x000000000182121d in my_malloc (key=150, size=40, flags=16) at /git/mysql-server_dbg/mysys/my_malloc.c:54
#14 0x000000000182f013 in lf_alloc_new (pins=0x7f32f444b080) at /git/mysql-server_dbg/mysys/lf_alloc-pin.c:438
#15 0x0000000001830345 in lf_hash_insert (hash=0x2ba4620 <digest_hash>, pins=0x7f32f444b080, data=0x7f3332206298) at /git/mysql-server_dbg/mysys/lf_hash.c:488
#16 0x00000000018632b8 in find_or_create_digest (thread=0x7f3329c1f600, digest_storage=0x7f32f441adc8, schema_name=0x7f32f441aeb0 "test", schema_name_length=4)
    at /git/mysql-server_dbg/storage/perfschema/pfs_digest.cc:290
#17 0x000000000185a493 in pfs_end_statement_v1 (locker=0x7f32f441ae08, stmt_da=0x7f32f441bd68) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:5407
#18 0x00000000014ecc73 in inline_mysql_end_statement (locker=0x7f32f441ae08, stmt_da=0x7f32f441bd68) at /git/mysql-server_dbg/include/mysql/psi/mysql_statement.h:228
#19 0x00000000014f224f in dispatch_command (thd=0x7f32f4419000, com_data=0x7f3332206cb0, command=COM_QUERY) at /git/mysql-server_dbg/sql/sql_parse.cc:1908
#20 0x00000000014efa44 in do_command (thd=0x7f32f4419000) at /git/mysql-server_dbg/sql/sql_parse.cc:999
#21 0x000000000161f9d0 in handle_connection (arg=0x7f33073ec860) at /git/mysql-server_dbg/sql/conn_handler/connection_handler_per_thread.cc:300
#22 0x00000000018534f9 in pfs_spawn_thread (arg=0x7f3315a76220) at /git/mysql-server_dbg/storage/perfschema/pfs.cc:2188
#23 0x00007f3331c0fdc5 in start_thread (arg=0x7f3332207700) at pthread_create.c:308
#24 0x00007f333006a73d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113
[20 Feb 2017 2:59] Roel Van de Paar
Perhaps related to bug 83798
[20 Feb 2017 3:00] Roel Van de Paar
(This bug is from an older run which still had the debug options added)
[20 Feb 2017 9:36] MySQL Verification Team
Version: '5.7.18-debug'  socket: ''  port: 3570  Source distribution PULL: 2017-FEB-01
2017-02-20T09:34:43.365936Z 3 [Note] Event Scheduler: scheduler thread started with id 3
Assertion failed: ! is_set() || m_can_overwrite_status, file C:\build\2017FEB02\mysql-5.7\sql\sql_error.cc, line 444
R6010
- abort() has been called
09:34:43 UTC - mysqld got exception 0x80000003 ;
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.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=151
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 = 68072 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x22ce1bd0d80
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...
7ff70bba8c75    mysqld.exe!my_sigabrt_handler()[my_thr_init.c:449]
7ff70c3b3a8f    mysqld.exe!raise()[winsig.c:594]
7ff70c3b0730    mysqld.exe!abort()[abort.c:82]
7ff70c399098    mysqld.exe!_wassert()[assert.c:156]
7ff70aebb80c    mysqld.exe!Diagnostics_area::set_error_status()[sql_error.cc:444]
7ff70af3d5bc    mysqld.exe!THD::raise_condition()[sql_class.cc:1453]
7ff70ae0cad6    mysqld.exe!my_message_sql()[mysqld.cc:2259]
7ff70bbafac0    mysqld.exe!my_error()[my_error.c:211]
7ff70bbac4ca    mysqld.exe!my_raw_malloc()[my_malloc.c:213]
7ff70bbabde8    mysqld.exe!my_malloc()[my_malloc.c:54]
7ff70bbcf520    mysqld.exe!lf_alloc_new()[lf_alloc-pin.c:439]
7ff70bbcfdbb    mysqld.exe!lf_hash_insert()[lf_hash.c:488]
7ff70c23ebf8    mysqld.exe!find_or_create_digest()[pfs_digest.cc:290]
7ff70c221085    mysqld.exe!pfs_end_statement_v1()[pfs.cc:5408]
7ff70aee3705    mysqld.exe!dispatch_command()[sql_parse.cc:1910]
7ff70aee05c3    mysqld.exe!do_command()[sql_parse.cc:999]
7ff70ae2b628    mysqld.exe!handle_connection()[connection_handler_per_thread.cc:300]
7ff70c2247c2    mysqld.exe!pfs_spawn_thread()[pfs.cc:2190]
7ff70bba7516    mysqld.exe!win_thread_start()[my_thread.c:37]
7ff70c3b32a5    mysqld.exe!_callthreadstartex()[threadex.c:376]
7ff70c3b34f7    mysqld.exe!_threadstartex()[threadex.c:359]
7ff9ae758364    KERNEL32.DLL!BaseThreadInitThunk()
7ff9b11070d1    ntdll.dll!RtlUserThreadStart()
[20 Feb 2017 9:39] MySQL Verification Team
Please read: https://bugs.mysql.com/bug.php?id=84755 below comment. Thanks.

 [8 Feb 13:10] Erlend Dahl

Your testcase sets a debug flag. These flags are used within the server to simulate an internal failure or to force a certain behaviour. This is not possible for normal users of the production version.

Their use is in carefully crafted testcases that take these intended behaviour changes into account. Used in another context, there is no guarantee they will work at all, and no point in trying to make them do so.

Such flags are in our opinion not suitable for randomized testing, and the fact that they create asserts or crashes can't be used to draw conclusions about regressions or quality of the server.

In our opinion, you should remove the use of debug flags from your scripts.
[20 Feb 2017 9:46] Laurynas Biveinis
IMHO out of all the debug flags the out-of-memory simulating one is in particular relevant for testing, and this bug is valid, as it uncovers missing OOM handling in some code paths
[28 Feb 2017 8:49] Roel Van de Paar
Miguel, please see comment by Laurynas