MySQL Bugs: #35589: SET PASSWORD caused a crash

Bug #35589	SET PASSWORD caused a crash
Submitted:	27 Mar 2008 7:38	Modified:	12 Mar 2010 17:50
Reporter:	Shane Bester (Platinum Quality Contributor)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Security: Privileges	Severity:	S3 (Non-critical)
Version:	5.1.23-debug	OS:	Any
Assigned to:	Magne Mæhre	CPU Architecture:	Any
Tags:	set password

Description:
Got a crash on SET PASSWORD command today:

stack trace:

mysqld.exe!strcmp
mysqld.exe!find_acl_user
mysqld.exe!change_password
mysqld.exe!set_var_password::update
mysqld.exe!sql_set_variables
mysqld.exe!mysql_execute_command
mysqld.exe!mysql_parse
mysqld.exe!dispatch_command
mysqld.exe!do_command
mysqld.exe!handle_one_connection
mysqld.exe!pthread_start
mysqld.exe!_callthreadstart
mysqld.exe!_threadstart

How to repeat:
will attach testcase later.

in find_acl_user(), acl_user->user was 0xfeeefeee or something.

testcase. if crash doesn't happen in 5 minutes, try increasing number of threads. run against debug build of 5.1 server

Attachment: bug35589.c (text/plain), 6.74 KiB.

same testcase for bug #35591 which is related.
there is a race condition causing a free or access of uninitialized memory.

for example if you drop a user and set a user password very quickly, the set password can crash because it thinks the list of is longer than is really is.

these bug #35589 and bug #35591 crashes are really hard to repeat.  it's probably easier for some developer to set it to verified after agreeing the crashes are possible in theory.

Verified as described by using test from Shane.

Also I will add my test because I had to change three rows.
I commented my_init().
I changed "int i" into "long i" because of testing on 64bit.
And there was a printf at the end of the code where my compiler didn't like output of a size_t value, so I changed "num" into "(int)num".

Here is the output from my 5.1 bk tree server:

Error: Freeing unallocated data at line 281, 'array.c'
Error: Freeing unallocated data at line 281, 'array.c'
Error: Freeing unallocated data at line 281, 'array.c'
...
Error: Freeing unallocated data at line 281, 'array.c'
Error: Freeing unallocated data at line 281, 'array.c'
Error: Freeing unallocated data at line 281, 'array.c'
080328 13:50:31 - mysqld got signal 10 ;
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=8388572
read_buffer_size=131072
max_used_connections=4
max_threads=151
threads_connected=4
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338264 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

signal 10: SIGBUS

here Shanes test case that I prepared for using on 64bit

Attachment: bug35589_changed_for_64bit.c (text/x-csrc), 6.78 KiB.

Observing seg.faults in different parts of the code when running the test code. Have done a few runs with MySQL 5.6 codebase (mysql-next-mr-bugfixing)

First run :

(gdb) where
#0  0x085507bf in mi_lock_database (info=0x90dd138, lock_type=1) at mi_locking.c:34
#1  0x0857155e in ha_myisam::external_lock (this=0x90fa400, thd=0x909bb08, lock_type=1) at ha_myisam.cc:1708
#2  0x08392342 in handler::ha_external_lock (this=0x90fa400, thd=0x909bb08, lock_type=1) at handler.cc:4647
#3  0x08259d66 in lock_external (thd=0x909bb08, tables=0xa7705cd4, count=5) at lock.cc:409
#4  0x0825b07c in mysql_lock_tables (thd=0x909bb08, tables=0x90e56a0, count=5, flags=4, need_reopen=0xa782587f) at lock.cc:308
#5  0x082bead3 in lock_tables (thd=0x909bb08, tables=0xa7825920, count=5, need_reopen=0xa782587f) at sql_base.cc:5343
#6  0x082c79d6 in open_and_lock_tables_derived (thd=0x909bb08, tables=0xa7825920, derived=false) at sql_base.cc:5030
#7  0x08280717 in simple_open_n_lock_tables (thd=0x909bb08, tables=0xa7825920) at mysql_priv.h:1505
#8  0x08339af0 in open_grant_tables (thd=0x909bb08, tables=0xa7825920) at sql_acl.cc:5175
#9  0x0834305b in mysql_drop_user (thd=0x909bb08, list=...) at sql_acl.cc:5846
#10 0x082799e8 in mysql_execute_command (thd=0x909bb08) at sql_parse.cc:3752
#11 0x0827db6e in mysql_parse (thd=0x909bb08, inBuf=0x90e55f8 "drop user 'u-102'", length=17, found_semicolon=0xa7827288) at sql_parse.cc:5993
#12 0x0827e649 in dispatch_command (command=COM_QUERY, thd=0x909bb08, packet=0x90cc071 "drop user 'u-102'", packet_length=17) at sql_parse.cc:1129
#13 0x0827f907 in do_command (thd=0x909bb08) at sql_parse.cc:799
#14 0x0826cbfb in handle_one_connection (arg=0x909bb08) at sql_connect.cc:1154
#15 0xb7fa94b5 in start_thread () from /lib/i686/cmov/libpthread.so.0
#16 0xb7e9aa5e in clone () from /lib/i686/cmov/libc.so.6
(gdb) p share
$1 = (MYISAM_SHARE *) 0x8f8f8f8f

Next run:

(gdb) where
#0  0x08337243 in get_grant_table (buff=0x8f8f8f8f, length=0xa7867738, not_used=1 '\001') at sql_acl.cc:2425
#1  0x085b15d8 in my_hash_key (hash=0x88a6d00, record=0x8f8f8f8f <Address 0x8f8f8f8f out of bounds>, length=0xa7867738, first=1 '\001') at hash.c:175
#2  0x085b189b in hashcmp (hash=0x88a6d00, pos=0x9112fd0, key=0xa78677d5 "u112", length=13) at hash.c:322
#3  0x085b16ef in my_hash_first (hash=0x88a6d00, key=0xa78677d5 "u112", length=13, current_record=0xa7867988) at hash.c:239
#4  0x0833bb37 in name_hash_search (name_hash=0x88a6d00, host=0x90b4a38 "127.0.0.1", ip=0x0, db=0x90b4800 "test", user=0x90b4a18 "u112", tname=0x90b4808 "t1", exact=true)
    at sql_acl.cc:2451
#5  0x08349f65 in table_hash_search (host=0x90b4a38 "127.0.0.1", ip=0x0, db=0x90b4800 "test", user=0x90b4a18 "u112", tname=0x90b4808 "t1", exact=true) at sql_acl.cc:2491
#6  0x08347b74 in mysql_table_grant (thd=0x88d9040, table_list=0x90b4830, user_list=..., columns=..., rights=0, revoke_grant=false) at sql_acl.cc:3126
#7  0x0827a241 in mysql_execute_command (thd=0x88d9040) at sql_parse.cc:3854
#8  0x0827db6e in mysql_parse (thd=0x88d9040, inBuf=0x90b4710 "grant select(id) on test.t1 to 'u112'@'127.0.0.1'", length=49, found_semicolon=0xa7869288)
    at sql_parse.cc:5993
#9  0x0827e649 in dispatch_command (command=COM_QUERY, thd=0x88d9040, packet=0x90ac6b1 "grant select(id) on test.t1 to 'u112'@'127.0.0.1'", packet_length=49)
    at sql_parse.cc:1129
#10 0x0827f907 in do_command (thd=0x88d9040) at sql_parse.cc:799
#11 0x0826cbfb in handle_one_connection (arg=0x88d9040) at sql_connect.cc:1154
#12 0xb7fa94b5 in start_thread () from /lib/i686/cmov/libpthread.so.0
#13 0xb7e9aa5e in clone () from /lib/i686/cmov/libc.so.6

Third run:

(gdb) 
#0  0x085a66a7 in free_root (root=0xa7868234, MyFlags=0) at my_alloc.c:347
#1  0x08341b6e in grant_reload (thd=0x907c9a8) at sql_acl.cc:3836
#2  0x0826e9dd in reload_acl_and_cache (thd=0x907c9a8, options=1, tables=0x0, write_to_binlog=0xa7868a6b) at sql_parse.cc:6833
#3  0x0827a405 in mysql_execute_command (thd=0x907c9a8) at sql_parse.cc:3903
#4  0x0827db6e in mysql_parse (thd=0x907c9a8, inBuf=0x90b5d28 "flush privileges", length=16, found_semicolon=0xa7869288) at sql_parse.cc:5993
#5  0x0827e649 in dispatch_command (command=COM_QUERY, thd=0x907c9a8, packet=0x90adcc9 "flush privileges", packet_length=16) at sql_parse.cc:1129
#6  0x0827f907 in do_command (thd=0x907c9a8) at sql_parse.cc:799
#7  0x0826cbfb in handle_one_connection (arg=0x907c9a8) at sql_connect.cc:1154
#8  0xb7fa94b5 in start_thread () from /lib/i686/cmov/libpthread.so.0
#9  0xb7e9aa5e in clone () from /lib/i686/cmov/libc.so.6
(gdb) list
342	  if (!(MyFlags & MY_KEEP_PREALLOC))
343	    root->pre_alloc=0;
344	
345	  for (next=root->used; next ;)
346	  {
347	    old=next; next= next->next ;
348	    if (old != root->pre_alloc)
349	      my_free(old,MYF(0));
350	  }
351	  for (next=root->free ; next ;)
(gdb) p old
$3 = (USED_MEM *) 0x8f8f8f8f
(gdb) p next
$4 = (USED_MEM *) 0x8f8f8f8f

The server outputs the following, in various numbers:
 Error: Freeing unallocated data at line 309, 'array.c'
 Error: Freeing wrong aligned pointer at line 309, 'array.c'
 Error: Freeing unallocated data at line 349, 'my_alloc.c'

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/92545

2916 Magne Mahre	2009-12-02
      Bug#35589 SET PASSWORD caused a crash
      Bug#35591 FLUSH PRIVILEGES caused a crash
      
      A race condition on the privilege hash tables (proc_priv_hash
      and func_priv_hash) caused one thread to try to delete elements
      that had already been deleted by another thread.
      
      The bug was caused by reading and saving the pointers to 
      the hash tables outside mutex protection.  This led to an
      inconsistency where a thread copied a pointer to a hash,
      another thread did the same, the first thread then deleted
      the hash, and the second then crashed when it in turn tried to
      delete the deleted hash.
      
      The fix is to ensure that operations on the shared hash structures
      happens under mutex protection (moving the locking up a little)

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/93167

2921 Magne Mahre	2009-12-08
      Bug#35589 SET PASSWORD caused a crash
      Bug#35591 FLUSH PRIVILEGES caused a crash
      
      A race condition on the privilege hash tables (proc_priv_hash
      and func_priv_hash) caused one thread to try to delete elements
      that had already been deleted by another thread.
      
      The bug was caused by reading and saving the pointers to 
      the hash tables outside mutex protection.  This led to an
      inconsistency where a thread copied a pointer to a hash,
      another thread did the same, the first thread then deleted
      the hash, and the second then crashed when it in turn tried to
      delete the deleted hash.
      
      The fix is to ensure that operations on the shared hash structures
      happens under mutex protection (moving the locking up a little)

Pushed into 6.0.14-alpha (revid:alik@sun.com-20091211055901-yp18b3c7xuhl87rf) (version source revid:alik@sun.com-20091211055401-43rjwq7gjed6ds83) (merge vers: 6.0.14-alpha) (pib:13)

Pushed into 5.6.0-beta (revid:alik@sun.com-20091211055628-ltr7fero363uev7r) (version source revid:alik@sun.com-20091211055453-717czhtezc74u8db) (merge vers: 5.6.0-beta) (pib:13)

Noted in 5.6.0, 6.0.14 changelogs.

A race condition on the privilege hash tables allowed one thread to
try to delete elements that had already been deleted by another
thread. A consequence was that SET PASSWORD or FLUSH PRIVILEGES could
cause a crash.

Backported to 5.1-bugteam   (next-mr revid: 2921)

Pushed into 5.1.43 (revid:joro@sun.com-20100115085139-qkh0i0fpohd9u9p5) (version source revid:magne.mahre@sun.com-20091218104834-cr0eno87brui12qy) (merge vers: 5.1.42) (pib:16)

Noted in 5.1.43 changelog.

Pushed into mysql-next-mr (revid:alik@sun.com-20100204063540-9czpdmpixi3iw2yb) (version source revid:alik@sun.com-20091224075613-es9uswo4lidkm3tj) (pib:16)

Pushed into 6.0.14-alpha (revid:alik@sun.com-20100205113942-oqovjy0eoqbarn7i) (version source revid:alik@sun.com-20100204064210-ljwanqvrjs83s1gq) (merge vers: 6.0.14-alpha) (pib:16)

Pushed into 5.5.2-m2 (revid:alik@sun.com-20100203172258-1n5dsotny40yufxw) (version source revid:alexey.kopytov@sun.com-20091223134205-pk9yvgfvpn3hy7lh) (merge vers: 5.5.1-m2) (pib:16)

Noted in 5.5.2 changelog. Already fixed in 6.0.x. Removed 5.6.0 entry, that has become Celosia.

Setting report to Need Merge pending push into Celosia.

Pushed into 5.5.3-m3 (revid:alik@sun.com-20100306103849-hha31z2enhh7jwt3) (version source revid:vvaintroub@mysql.com-20091211201717-03qf8ckwiw0np80p) (merge vers: 5.6.0-beta) (pib:16)

Already fixed in earlier 5.5.x.

Pushed into 5.1.44-ndb-7.0.14 (revid:jonas@mysql.com-20100312135944-t0z8s1da2orvl66x) (version source revid:jonas@mysql.com-20100312115609-woou0te4a6s4ae9y) (merge vers: 5.1.44-ndb-7.0.14) (pib:16)

Pushed into 5.1.44-ndb-6.2.19 (revid:jonas@mysql.com-20100312134846-tuqhd9w3tv4xgl3d) (version source revid:jonas@mysql.com-20100312060623-mx6407w2vx76h3by) (merge vers: 5.1.44-ndb-6.2.19) (pib:16)

Pushed into 5.1.44-ndb-6.3.33 (revid:jonas@mysql.com-20100312135724-xcw8vw2lu3mijrhn) (version source revid:jonas@mysql.com-20100312103652-snkltsd197l7q2yg) (merge vers: 5.1.44-ndb-6.3.33) (pib:16)