| Bug #65711 | Server crashes in intern_plugin_lock on concurrent install plugin / set variable | ||
|---|---|---|---|
| Submitted: | 22 Jun 2012 13:30 | Modified: | 22 Jun 2012 14:04 |
| Reporter: | Elena Stepanova | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Server: Options | Severity: | S3 (Non-critical) |
| Version: | 5.5.25, 5.5.26, 5.6.5 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[22 Jun 2012 13:30]
Elena Stepanova
[22 Jun 2012 14:04]
Valeriy Kravchuk
Thank you for the bug report. Verified on Mac OS X, crashed on second run: macbook-pro:mysql-test openxs$ ./mtr bug65711 Logging: ./mtr bug65711 120622 17:02:14 [Warning] Setting lower_case_table_names=2 because file system for /var/folders/dX/dXCzvuSlHX4Op1g-o1jIWk+++TI/-Tmp-/ijkGNSZUzL/ is case insensitive 120622 17:02:14 [Note] Plugin 'FEDERATED' is disabled. MySQL Version 5.5.26 Checking supported features... - skipping ndbcluster - SSL connections supported - binaries are debug compiled Collecting tests... vardir: /Users/openxs/dbs/5.5/mysql-test/var Checking leftover processes... Removing old var directory... Creating var directory '/Users/openxs/dbs/5.5/mysql-test/var'... Installing system database... Using server port 58190 ============================================================================== TEST RESULT TIME (ms) or COMMENT -------------------------------------------------------------------------- worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 main.bug65711 [ fail ] Test ended at 2012-06-22 17:02:37 CURRENT_TEST: main.bug65711 mysqltest: At line 10: query 'SET GLOBAL rpl_semi_sync_master_enabled = ON' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 0... The result from queries just before the failure was: SET GLOBAL rpl_semi_sync_master_enabled = OFF; UNINSTALL PLUGIN rpl_semi_sync_master; INSTALL PLUGIN rpl_semi_sync_master SONAME 'semisync_master.so'; Server [mysqld.1 - pid: 36110, winpid: 36110, exit: 256] failed during test run Server log from this test: ----------SERVER LOG START----------- 120622 17:02:24 [Warning] Setting lower_case_table_names=2 because file system for /Users/openxs/dbs/5.5/mysql-test/var/mysqld.1/data/ is case insensitive 120622 17:02:24 [Note] Plugin 'FEDERATED' is disabled. 120622 17:02:24 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!! 120622 17:02:24 InnoDB: The InnoDB memory heap is disabled 120622 17:02:24 InnoDB: Mutexes and rw_locks use GCC atomic builtins 120622 17:02:24 InnoDB: Compressed tables use zlib 1.2.3 120622 17:02:25 InnoDB: Initializing buffer pool, size = 8.0M 120622 17:02:25 InnoDB: Completed initialization of buffer pool 120622 17:02:25 InnoDB: highest supported file format is Barracuda. 120622 17:02:25 InnoDB: Waiting for the background threads to start 120622 17:02:26 InnoDB: 1.1.8 started; log sequence number 1595675 120622 17:02:26 [Note] Server hostname (bind-address): '0.0.0.0'; port: 13000 120622 17:02:26 [Note] - '0.0.0.0' resolves to '0.0.0.0'; 120622 17:02:26 [Note] Server socket created on IP: '0.0.0.0'. 120622 17:02:26 [Note] Event Scheduler: Loaded 0 events 120622 17:02:26 [Note] /Users/openxs/dbs/5.5/bin/mysqld: ready for connections. Version: '5.5.26-debug-log' socket: '/Users/openxs/dbs/5.5/mysql-test/var/tmp/mysqld.1.sock' port: 13000 Source distribution 14:02:26 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=1048576 read_buffer_size=131072 max_used_connections=2 max_threads=151 thread_count=2 connection_count=2 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60768 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x101835000 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 = 10517de68 thread_stack 0x40000 0 mysqld 0x0000000000387643 my_print_stacktrace + 50 1 mysqld 0x00000000000355ee handle_fatal_signal + 1148 2 libSystem.B.dylib 0x00000000805ed3aa _sigtramp + 26 3 mysqld 0x0000000000565a22 _db_end_ + 416 4 mysqld 0x000000000023485a _Z12find_sys_varP3THDPKcj + 248 5 mysqld 0x000000000032cadf _Z21case_stmt_action_caseP3LEX + 119 6 mysqld 0x00000000003525bb _Z10MYSQLparsePv + 150191 7 mysqld 0x000000000020bf75 _Z9parse_sqlP3THDP12Parser_stateP19Object_creation_ctx + 209 8 mysqld 0x000000000021b3e8 _Z11mysql_parseP3THDPcjP12Parser_state + 174 9 mysqld 0x000000000021c2ce _Z16dispatch_command19enum_server_commandP3THDPcj + 3026 10 mysqld 0x000000000021d959 _Z10do_commandP3THD + 633 11 mysqld 0x000000000030aced _Z24do_handle_one_connectionP3THD + 397 12 mysqld 0x000000000030adb3 handle_one_connection + 45 13 mysqld 0x0000000000542dab pfs_spawn_thread + 147 14 libSystem.B.dylib 0x00000000805b5dcb _pthread_start + 316 15 libSystem.B.dylib 0x00000000805b5c8d thread_start + 13 Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (1018e8410): SET GLOBAL rpl_semi_sync_master_enabled = ON Connection ID (thread ID): 2 Status: 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. Writing a core file ----------SERVER LOG END-------------
[15 Aug 2012 2:52]
liu hickey
For mysql_install_plugin, the logic is first plugin_add, and then plugin_initialize.
plugin->state is set to PLUGIN_IS_READY until plugin->init() succeeded in plugin_initialize(), while the plugin might already registed to system_variable_hash.
Therefore, for such piece code below, it might be problematic: the var is found in system_variable_hash, but it's plugin in still uninitialized.
intern_find_sys_var
if ((var= intern_find_sys_var(str, length)) &&
(pi= var->cast_pluginvar()))
{
mysql_rwlock_unlock(&LOCK_system_variables_hash);
LEX *lex= thd ? thd->lex : 0;
if (!(plugin= my_intern_plugin_lock(lex, plugin_int_to_ref(pi->plugin))))
var= NULL; /* failed to lock it, it must be uninstalling */
else
if (!(plugin_state(plugin) & PLUGIN_IS_READY))
{
/* initialization not completed */
var= NULL;
intern_plugin_unlock(lex, plugin);
}
}
The workaround is to void the plugin still be NULL case in my_intern_plugin_lock:
--- sql/sql_plugin.cc (revision 88)
+++ sql/sql_plugin.cc (working copy)
@@ -713,6 +713,9 @@
static plugin_ref intern_plugin_lock(LEX *lex, plugin_ref rc)
{
st_plugin_int *pi= plugin_ref_to_int(rc);
+ if (!pi)
+ DBUG_RETURN(NULL);
+
DBUG_ENTER("intern_plugin_lock");
mysql_mutex_assert_owner(&LOCK_plugin);
Also, we could adjust the logic mentioned above, adding a flag to indicate the plugin_initialize is successful after plugin_add, such as a bool var of plugin_initized for sys_var_pluginvar, and it's set to true after plugin->init() successful, then check the flag before calling the intern_plugin_lock(). But it's more simple and clear with the workaround patch above.
