Bug #86290 Assertion `rc == TYPE_OK' failed.
Submitted: 12 May 2017 3:35 Modified: 21 Aug 2017 13:11
Reporter: Roel Van de Paar Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Data Dictionary Severity:S1 (Critical)
Version:8.0.1 OS:Any
Assigned to: CPU Architecture:Any

[12 May 2017 3:35] Roel Van de Paar
Description:
mysqld: /git/mysql-8.0.1-dmr_dbg/sql/dd/impl/raw/raw_record.cc:178: bool dd::Raw_record::store(int, ulonglong, bool): Assertion `rc == TYPE_OK' failed.

Core was generated by `/sda/MS120517-mysql-8.0.1-dmr-linux-x86_64-debug/bin/mysqld --no-defaults --cor'.
Program terminated with signal 6, Aborted.
#0  0x00007fd2b6035741 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) t
[Current thread is 1 (Thread 0x7fd2b65e7700 (LWP 8850))]
(gdb) bt
#0  0x00007fd2b6035741 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000002609fc9 in my_write_core (sig=6) at /git/mysql-8.0.1-dmr_dbg/mysys/stacktrace.cc:291
#2  0x0000000001d14c5c in handle_fatal_signal (sig=6) at /git/mysql-8.0.1-dmr_dbg/sql/signal_handler.cc:231
#3  <signal handler called>
#4  0x00007fd2b43c91d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007fd2b43ca8c8 in __GI_abort () at abort.c:90
#6  0x00007fd2b43c2146 in __assert_fail_base (fmt=0x7fd2b45133a8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", 
    assertion=assertion@entry=0x32f2183 "rc == TYPE_OK", 
    file=file@entry=0x32f2128 "/git/mysql-8.0.1-dmr_dbg/sql/dd/impl/raw/raw_record.cc", line=line@entry=178, 
    function=function@entry=0x32f2380 <dd::Raw_record::store(int, unsigned long long, bool)::__PRETTY_FUNCTION__> "bool dd::Raw_record::store(int, ulonglong, bool)") at assert.c:92
#7  0x00007fd2b43c21f2 in __GI___assert_fail (assertion=0x32f2183 "rc == TYPE_OK", 
    file=0x32f2128 "/git/mysql-8.0.1-dmr_dbg/sql/dd/impl/raw/raw_record.cc", line=178, 
    function=0x32f2380 <dd::Raw_record::store(int, unsigned long long, bool)::__PRETTY_FUNCTION__> "bool dd::Raw_record::store(int, ulonglong, bool)") at assert.c:101
#8  0x0000000001c77edf in dd::Raw_record::store (this=0x7fd26f01a078, field_no=15, ull=19700101001640, is_null=false)
    at /git/mysql-8.0.1-dmr_dbg/sql/dd/impl/raw/raw_record.cc:178
#9  0x0000000001cb67ed in dd::Event_impl::store_attributes (this=0x7fd26f016100, r=0x7fd26f01a078)
    at /git/mysql-8.0.1-dmr_dbg/sql/dd/impl/types/event_impl.cc:191
#10 0x0000000001ceed1e in dd::Weak_object_impl::store (this=0x7fd26f016100, otx=0x7fd2b65e5cd0)
    at /git/mysql-8.0.1-dmr_dbg/sql/dd/impl/types/weak_object_impl.cc:101
#11 0x0000000001c69cce in dd::cache::Storage_adapter::store<dd::Event> (thd=0x7fd26ed51000, object=0x7fd26f016120)
    at /git/mysql-8.0.1-dmr_dbg/sql/dd/impl/cache/storage_adapter.cc:306
#12 0x0000000001bb6b2b in dd::cache::Dictionary_client::update<dd::Event> (this=0x7fd26ed55000, new_object=0x7fd26f016120)
    at /git/mysql-8.0.1-dmr_dbg/sql/dd/impl/cache/dictionary_client.cc:2166
#13 0x0000000002045710 in dd::update_event_time_and_status (thd=0x7fd26ed51000, event=0x7fd26f016120, last_executed=1494555912, 
    status=2) at /git/mysql-8.0.1-dmr_dbg/sql/dd/dd_event.cc:424
#14 0x000000000206c288 in Event_db_repository::update_timing_fields_for_event (this=0x7fd2a67ff338, thd=0x7fd26ed51000, 
    event_db_name=..., event_name=..., last_executed=1494555912, status=2) at /git/mysql-8.0.1-dmr_dbg/sql/event_db_repository.cc:394
#15 0x000000000206f41d in Event_queue::get_top_for_execution_if_time (this=0x7fd26e5e1c00, thd=0x7fd26ed51000, 
    event_name=0x7fd2b65e6d10) at /git/mysql-8.0.1-dmr_dbg/sql/event_queue.cc:665
#16 0x0000000002072cdf in Event_scheduler::run (this=0x7fd26e5e1d00, thd=0x7fd26ed51000)
    at /git/mysql-8.0.1-dmr_dbg/sql/event_scheduler.cc:587
#17 0x00000000020720f7 in event_scheduler_thread (arg=0x7fd26ec33270) at /git/mysql-8.0.1-dmr_dbg/sql/event_scheduler.cc:276
#18 0x000000000263cdae in pfs_spawn_thread (arg=0x7fd26ecb8520) at /git/mysql-8.0.1-dmr_dbg/storage/perfschema/pfs.cc:2407
#19 0x00007fd2b6030dc5 in start_thread (arg=0x7fd2b65e7700) at pthread_create.c:308
#20 0x00007fd2b448b73d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

How to repeat:
SET timestamp=1000;
SET time_zone='+00:00';
USE sys;
CREATE EVENT event1 on schedule every 15 minute starts now()ends date_add(now(),interval 5 hour) DO begin end;
CREATE EVENT root11 on schedule every '20:25' day_hour do select 1;
SET GLOBAL event_scheduler=1;
SELECT 1;  # Shows server is gone
[14 May 2017 16:37] MySQL Verification Team
Thank you for the bug report. I couldn't repeat on Windows with 8.0.1 and on Linux with most recent source. Any else instructions for?

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 5
Server version: 8.0.1-dmr-debug MySQL Community Server - Debug (GPL)

Copyright (c) 2000, 2017, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> SET timestamp=1000;
Query OK, 0 rows affected (0.00 sec)

mysql> SET time_zone='+00:00';
Query OK, 0 rows affected (0.00 sec)

mysql> USE sys;
Database changed
mysql> CREATE EVENT event1 on schedule every 15 minute starts now()ends date_add(now(),interval 5 hour) DO begin end;
Query OK, 0 rows affected (0.06 sec)

mysql> CREATE EVENT root11 on schedule every '20:25' day_hour do select 1;
Query OK, 0 rows affected (0.06 sec)

mysql> SET GLOBAL event_scheduler=1;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT 1;  # Shows server is gone
+---+
| 1 |
+---+
| 1 |
+---+
1 row in set (0.00 sec)
[17 May 2017 7:06] Roel Van de Paar
This was on Centos 7 x64 with timezone (OS level) set to Sydney time. It was with source downloaded from mysql.com.
[17 May 2017 7:07] Roel Van de Paar
May be good to try; download source, compile as debug, use Centos 7 with timezone set to Sydney time.
[17 May 2017 8:27] MySQL Verification Team
Version: '8.0.1-dmr-debug' MySQL Community Server - Debug (GPL)
[Note] Event Scheduler: scheduler thread started with id 4
[Note] Event Scheduler: Last execution of sys.event1. Dropping.
Assertion failed: rc == TYPE_OK, file raw_record.cc, line 178
abort() has been called08:26:32 UTC - mysqld got exception 0x80000003 ;

mysqld-debug.exe!my_sigabrt_handler()[my_thr_init.cc:474]
  ucrtbased.dll!raise()
  ucrtbased.dll!abort()
  ucrtbased.dll!_get_wide_winmain_command_line()
  ucrtbased.dll!_get_wide_winmain_command_line()
  ucrtbased.dll!_get_wide_winmain_command_line()
  ucrtbased.dll!_wassert()
mysqld-debug.exe!dd::Raw_record::store()[raw_record.cc:178]
mysqld-debug.exe!dd::Event_impl::store_attributes()[event_impl.cc:181]
mysqld-debug.exe!dd::Weak_object_impl::store()[weak_object_impl.cc:101]
mysqld-debug.exe!dd::cache::Storage_adapter::store<dd::Event>()[storage_adapter.cc:306]
mysqld-debug.exe!dd::cache::Dictionary_client::update<dd::Event>()[dictionary_client.cc:2166]
mysqld-debug.exe!dd::update_event_time_and_status()[dd_event.cc:424]
mysqld-debug.exe!Event_db_repository::update_timing_fields_for_event()[event_db_repository.cc:394]
mysqld-debug.exe!Event_queue::get_top_for_execution_if_time()[event_queue.cc:667]
mysqld-debug.exe!Event_scheduler::run()[event_scheduler.cc:587]
mysqld-debug.exe!event_scheduler_thread()[event_scheduler.cc:277]
mysqld-debug.exe!pfs_spawn_thread()[pfs.cc:2409]
mysqld-debug.exe!win_thread_start()[my_thread.cc:42]
[17 May 2017 8:29] MySQL Verification Team
Thanks for the report!  Repeated on recent git build.

[Note] mysqld-debug.exe: ready for connections. Version: '8.0.2-dmr-debug'  socket: ''  port: 3306  (Built on 2017/05/13)
[Note] Event Scheduler: scheduler thread started with id 5
[Note] Event Scheduler: Last execution of sys.event1. Dropping.
Assertion failed: rc == TYPE_OK, file raw_record.cc, line 178
abort() has been called08:27:48 UTC - mysqld got exception 0x80000003 ;

mysqld-debug.exe!my_sigabrt_handler()[my_thr_init.cc:418]
  ucrtbased.dll!raise()
  ucrtbased.dll!abort()
  ucrtbased.dll!_get_wide_winmain_command_line()
  ucrtbased.dll!_get_wide_winmain_command_line()
  ucrtbased.dll!_get_wide_winmain_command_line()
  ucrtbased.dll!_wassert()
mysqld-debug.exe!dd::Raw_record::store()[raw_record.cc:178]
mysqld-debug.exe!dd::Event_impl::store_attributes()[event_impl.cc:181]
mysqld-debug.exe!dd::Weak_object_impl::store()[weak_object_impl.cc:102]
mysqld-debug.exe!dd::cache::Storage_adapter::store<dd::Event>()[storage_adapter.cc:306]
mysqld-debug.exe!dd::cache::Dictionary_client::update<dd::Event>()[dictionary_client.cc:2262]
mysqld-debug.exe!dd::update_event_time_and_status()[dd_event.cc:431]
mysqld-debug.exe!Event_db_repository::update_timing_fields_for_event()[event_db_repository.cc:395]
mysqld-debug.exe!Event_queue::get_top_for_execution_if_time()[event_queue.cc:687]
mysqld-debug.exe!Event_scheduler::run()[event_scheduler.cc:593]
mysqld-debug.exe!event_scheduler_thread()[event_scheduler.cc:285]
mysqld-debug.exe!pfs_spawn_thread()[pfs.cc:2395]
mysqld-debug.exe!win_thread_start()[my_thread.cc:42]
[26 Jul 2017 6:52] MySQL Verification Team
Still affects recent trunk:

mysqld-debug.exe: Version: '8.0.3-rc-debug'  socket: ''  port: 3306  (Built on 2017/07/20)

Assertion failed: rc == TYPE_OK, file raw_record.cc, line 179
abort() has been called
mysqld got exception 0x80000003 ;

mysqld-debug.exe!my_sigabrt_handler()[my_thr_init.cc:418]
  ucrtbased.dll!raise()
  ucrtbased.dll!abort()
  ucrtbased.dll!_get_wide_winmain_command_line()
  ucrtbased.dll!_get_wide_winmain_command_line()
  ucrtbased.dll!_get_wide_winmain_command_line()
  ucrtbased.dll!_wassert()
mysqld-debug.exe!dd::Raw_record::store()[raw_record.cc:179]
mysqld-debug.exe!dd::Event_impl::store_attributes()[event_impl.cc:181]
mysqld-debug.exe!dd::Weak_object_impl::store()[weak_object_impl.cc:102]
mysqld-debug.exe!dd::cache::Storage_adapter::store<dd::Event>()[storage_adapter.cc:308]
mysqld-debug.exe!dd::cache::Dictionary_client::update<dd::Event>()[dictionary_client.cc:2320]
mysqld-debug.exe!dd::update_event_time_and_status()[dd_event.cc:431]
mysqld-debug.exe!Event_db_repository::update_timing_fields_for_event()[event_db_repository.cc:369]
mysqld-debug.exe!Event_queue::get_top_for_execution_if_time()[event_queue.cc:712]
mysqld-debug.exe!Event_scheduler::run()[event_scheduler.cc:593]
mysqld-debug.exe!event_scheduler_thread()[event_scheduler.cc:285]
mysqld-debug.exe!pfs_spawn_thread()[pfs.cc:2991]
mysqld-debug.exe!win_thread_start()[my_thread.cc:42]
[21 Aug 2017 13:11] Daniel Price
Posted by developer:
 
Fixed as of the upcoming 8.0.3 release, and here's the changelog entry:

Timestamp data copied from the data dictionary cache during a DDL
operation was converted using a time_zone value that was no longer valid.
The resulting timestamp data was incorrect, causing an error in release
builds and an assertion failure in debug builds.