Bug #42188 crash and/or memory corruption with user variables in trigger

• Submitted: 18 Jan 2009 21:39
• Modified: 11 Feb 2009 3:39
• Reporter: Frederic Steinfels
• Status: Closed
• Category: MySQL Server: Stored Routines
• Severity: S1 (Critical)
• Version: 5.1.29, 5.1.30, 5.1.31, 6.0.8, 6.0.10
• OS: Any
• Assigned to: Gleb Shchepa
• CPU Architecture: Any
• Tags: corruption, crash, mysql_change_user, regression, stored procedure, trigger

[18 Jan 2009 21:39] Frederic Steinfels

Description:
MySQL is crashing with my stored procedure and destroying all tables involved.

==> /var/log/mysqld.log <==
090118 22:36:35 - 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=2147483648
read_buffer_size=536870912
max_used_connections=28
max_threads=200
threads_connected=6
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 211814383 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x7fe1f4467400
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 = 0x7fe1f8540020 thread_stack 0x100000
/usr/libexec/mysqld(my_print_stacktrace+0x29) [0x91e4e9]
/usr/libexec/mysqld(handle_segfault+0x373) [0x5f6453]
/lib64/libpthread.so.0 [0x38df40f0f0]
/lib64/libc.so.6(cfree+0x25) [0x38de87a435]
/usr/libexec/mysqld [0x573325]
/usr/libexec/mysqld(Item_func_set_user_var::update_hash(void*, unsigned int, Item_result, charset_info_st*, Derivation, bool)+0x66) [0x5789d6]
/usr/libexec/mysqld(Item_func_set_user_var::update()+0x112) [0x578b32]
/usr/libexec/mysqld(set_var_user::update(THD*)+0xd) [0x6140ed]
/usr/libexec/mysqld(sql_set_variables(THD*, List<set_var_base>*)+0x89) [0x6141f9]
/usr/libexec/mysqld(mysql_execute_command(THD*)+0x2af1) [0x603c91]
/usr/libexec/mysqld(sp_instr_stmt::exec_core(THD*, unsigned int*)+0x1c) [0x72dfbc]
/usr/libexec/mysqld(sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*)+0xca) [0x72e15a]
/usr/libexec/mysqld(sp_instr_stmt::execute(THD*, unsigned int*)+0x114) [0x732d24]
/usr/libexec/mysqld(sp_head::execute(THD*)+0x618) [0x730c78]
/usr/libexec/mysqld(sp_head::execute_trigger(THD*, st_mysql_lex_string const*, st_mysql_lex_string const*, st_grant_info*)+0x1d9) [0x731559]
/usr/libexec/mysqld(Table_triggers_list::process_triggers(THD*, trg_event_type, trg_action_time_type, bool)+0xe3) [0x73b5c3]
/usr/libexec/mysqld(mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, enum_duplicates, bool)+0xd58) [0x67ace8]
/usr/libexec/mysqld(mysql_execute_command(THD*)+0xedf) [0x60207f]
/usr/libexec/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x212) [0x606a12]
/usr/libexec/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0xf0b) [0x608beb]
/usr/libexec/mysqld(do_command(THD*)+0xe8) [0x609298]
/usr/libexec/mysqld(handle_one_connection+0x226) [0x5fca96]
/lib64/libpthread.so.0 [0x38df4073da]
/lib64/libc.so.6(clone+0x6d) [0x38de8e62bd]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x89ca310 = SET @delayedbarupdate='0'
thd->thread_id=6408
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.
090118 22:36:35 mysqld_safe Number of processes running now: 0
090118 22:36:35 mysqld_safe mysqld restarted
090118 22:36:35 [Warning] The syntax '--log_slow_queries' is deprecated and will be removed in MySQL 7.0. Please use '--slow_query_log'/'--slow_query_log_file' instead.
090118 22:36:36  InnoDB: Started; log sequence number 0 43655
090118 22:36:36 [Note] Event Scheduler: Loaded 0 events
090118 22:36:36 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.1.30-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL) by Remi

==> /var/log/mysqlslow.log <==
/usr/libexec/mysqld, Version: 5.1.30-log (MySQL Community Server (GPL) by Remi). started with:
Tcp port: 0  Unix socket: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument

==> /var/log/mysqld.log <==
090118 22:37:03 [Note] Found 101 of 72 rows when repairing './dvdupgrades/retree'

How to repeat:
TBA

[19 Jan 2009 15:12] Frederic Steinfels

I have been able to track down the problem to the usage of @ variables in stored procedures. When replacing this with local variables read/written from/to tables, everything goes well. When using @ variables, MySQL will crash.

[19 Jan 2009 18:07] MySQL Verification Team

testcase. run against mysqld-debug or mysqld under valgrind if crashes don't happen soon

Attachment: bug42188.c (text/plain), 6.96 KiB.

[19 Jan 2009 18:16] MySQL Verification Team

this is a recent regression introduced in 5.1.29 afaict.

[21 Jan 2009 5:43] Gleb Shchepa

Small test case is:

CREATE TABLE t1 (i INT);
CREATE TRIGGER t_after_insert AFTER INSERT ON t1 FOR EACH ROW SET @bug42188 = 10;
INSERT INTO t1 VALUES (1);
--change_user
INSERT INTO t1 VALUES (1);
DROP TABLE t1;

mysql_change_user() API call forces TDH::cleanup() call that frees user variable entries, however it doesn't reset Item_func_set_user_var::entry to NULL because Item_func_set_user_var::cleanup() is not overloaded.
So, Item_func_set_user_var::entry holds a pointer to freed memory,
this causes a crash.

[21 Jan 2009 6:14] Bugs System

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/63656

2748 Gleb Shchepa	2009-01-21
      Bug#42188: crash and/or memory corruption with user variables 
                 in trigger
      
      Interchangeable calls to the mysql_change_user client function 
      and invocations of a trigger changing some user variable caused 
      a memory corruption and a crash.
      
      The mysql_change_user API call forces TDH::cleanup() on a server 
      that frees user variable entries.
      However it didn't reset Item_func_set_user_var::entry to NULL 
      because Item_func_set_user_var::cleanup() was not overloaded.
      So, Item_func_set_user_var::entry held a pointer to freed memory,
      that caused a crash.
      
      The Item_func_set_user_var::cleanup method has been overloaded
      to cleanup the Item_func_set_user_var::entry field.

[24 Jan 2009 14:11] Bugs System

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/63980

2746 Gleb Shchepa	2009-01-24
      Bug #42188: After-push test file update (see bug 42321)

[3 Feb 2009 9:41] Bugs System

Pushed into 5.1.32 (revid:[e-mail]-20090203090549-gos3v4320vimrzg6) (version source revid:[e-mail]-20090124140710-17brta8t95ds3xfy) (merge vers: 5.1.32) (pib:6)

[4 Feb 2009 11:17] Bugs System

Pushed into 6.0.10-alpha (revid:[e-mail]-20090204104420-mw1i2u9lum4bxjo6) (version source revid:[e-mail]-20090124142202-badofkubjngzuo4r) (merge vers: 6.0.10-alpha) (pib:6)

[11 Feb 2009 3:39] Paul DuBois

Noted in 5.1.32, 6.0.10 changelog.

User variables within triggers could cause a crash if the
mysql_change_user() C API function was invoked.

[17 Feb 2009 15:01] Bugs System

Pushed into 5.1.32-ndb-6.3.23 (revid:[e-mail]-20090217131017-6u8qz1edkjfiobef) (version source revid:[e-mail]-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)

[17 Feb 2009 16:48] Bugs System

Pushed into 5.1.32-ndb-6.4.3 (revid:[e-mail]-20090217134419-5ha6xg4dpedrbmau) (version source revid:[e-mail]-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)

[17 Feb 2009 18:24] Bugs System

Pushed into 5.1.32-ndb-6.2.17 (revid:[e-mail]-20090217134216-5699eq74ws4oxa0j) (version source revid:[e-mail]-20090202111723-1zzwax187rtls913) (merge vers: 5.1.32-ndb-6.2.17) (pib:6)

[19 Feb 2009 8:20] Valeriy Kravchuk

Bug #42975 was marked as a duplicate of this one.