MySQL Bugs: #48536: slave thread can crash if event scheduler fails to read event table at startup

Bug #48536	slave thread can crash if event scheduler fails to read event table at startup
Submitted:	4 Nov 2009 16:51	Modified:	10 Nov 2012 16:53
Reporter:	Shane Bester (Platinum Quality Contributor)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S1 (Critical)
Version:	5.1.40	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
if you have an active replicating slave, and the 'event' table becomes unreadable or corrupted, or compressed using myisampack, the following happens on startup of mysqld:

091101 01:14:31 [Note] Plugin 'FEDERATED' is disabled.
091101 01:14:31 [Note] Plugin 'InnoDB' is disabled.
091101 01:14:31 [ERROR] Event Scheduler: Failed to open table mysql.event
091101 01:14:31 [ERROR] Event Scheduler: Error while loading from disk.
091101 01:14:31 [Note] Event Scheduler: Purging the queue. 0 events
091101 01:14:31 [ERROR] Aborting

At the same time as the above is happening, the slave thread is busy initializing,
and ends up crashing in plugin_thdvar_init()

How to repeat:
will make a server patch to add a sleep in the correct place to show the problem.
it's a race condition that happens.

how to repeat:
1) setup a slave server so that slave thread runs upon startup.
2) shutdown slave. un myisampack on the mysql.event table, then run myisamchk -rq on that table.
3) startup slave with --event-scheduler --skip-innodb --server-id=2 options.  slave thread crashes the server after event scheduler decides to shutdown server.

stack trace from a crash on 5.1.40:

091112 15:17:19 [Note] Plugin 'FEDERATED' is disabled.
091112 15:17:19 [Note] Plugin 'InnoDB' is disabled.
091112 15:17:19 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may br
091112 15:17:19 [Note] Slave SQL thread initialized, starting replication in log 'box1-bin.000001' a
091112 15:17:19 [ERROR] Event Scheduler: Failed to open table mysql.event
091112 15:17:19 [ERROR] Event Scheduler: Error while loading from disk.
091112 15:17:19 [Note] Event Scheduler: Purging the queue. 0 events
091112 15:17:19 [ERROR] Aborting

091112 15:17:19 [Warning] Plugin 'MyISAM' will be forced to shutdown
091112 15:17:19 [ERROR] Plugin 'MyISAM' has ref_count=2 after shutdown.
091112 15:17:19 [Note] mysqld: Shutdown complete

091112 15:17:19 - mysqld got exception 0xc0000005 ;

thd: 0x4ea6420
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...
7D628810    ntdll.dll!RtlCheckForOrphanedCriticalSections()
7D62889F    ntdll.dll!RtlCheckForOrphanedCriticalSections()
004A0A11    mysqld.exe!change_rpl_status()[repl_failsafe.cc:113]
0046F621    mysqld.exe!connect_to_master()[slave.cc:3886]
0046F14B    mysqld.exe!safe_connect()[slave.cc:3788]
00468ADA    mysqld.exe!handle_slave_io()[slave.cc:2544]
008DAA76    mysqld.exe!pthread_start()[my_winthread.c:85]
008B6861    mysqld.exe!_callthreadstart()[thread.c:293]
008B6807    mysqld.exe!_threadstart()[thread.c:277]
7D4E0017    kernel32.dll!FlsSetValue()
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 00000000=(null)
thd->thread_id=1
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.

you may have to start mysqld in a loop a few times to see a crash, but it happens in seconds.

The point of this bug is that error handling is broken. Any failure to load shouldn't result in a crash.

the workaround is excellent because dba should never tamper with the tables in `mysql` database.  this includes myisampacking them, altering them, or changing the engine.

Issue has already been fixed in 5.5+. Current bug report adds only a test case. No changelog entry needed.

In my case it was missing permissions. On the DataDir Root folder I have set the Service account Full permissions. It depends on the account you have configured to run the service. Mine is "Network service" (basic account configured by Installer).

My configuration:
Windows 2012 R2
MySQL Data Dir: D:\Mysql\data