Bug #38692 concurrent inserts cause valgrind errors in Query_cache::invalidate
Submitted: 9 Aug 2008 19:14 Modified: 21 Oct 2008 19:40
Reporter: Shane Bester
Status: Closed
Category:Server: Query Cache Severity:S1 (Critical)
Version:5.1.26, 5.1.28, 6.0.7 OS:Any
Assigned to: Kristofer Pettersson Target Version:5.1+
Triage: Triaged: D2 (Serious)

[9 Aug 2008 19:14] Shane Bester 
Description:
inserting with concurrent inserts enabled gave these errors:

==16055== 1 errors in context 1 of 3:
==16055== Invalid read of size 4
0x82BEC69: Query_cache::invalidate (sql_cache.cc:2531)
0x8234409: mysql_insert (sql_insert.cc:919)
0x81D724D: mysql_execute_command (sql_parse.cc:2953)
0x81DB910: mysql_parse (sql_parse.cc:5645)
0x81D424D: dispatch_command (sql_parse.cc:1137)
0x81D3DD2: do_command (sql_parse.cc:794)
0x81D2300: handle_one_connection (sql_connect.cc:1115)
0x4893DA: start_thread (in /lib/libpthread-2.5.so)
0x3D606D: clone (in /lib/libc-2.5.so)

Address 0x635D264 is 284 bytes inside a block of size 996 free'd
0x400501A: free (vg_replace_malloc.c:233)
0x840DF4D: my_no_flags_free (my_malloc.c:59)
0x840E6E4: free_root (my_alloc.c:355)
0x820C8D5: free_table_share (table.cc:431)
0x8209C26: table_def_free_entry (sql_base.cc:271)
0x84138D1: hash_delete (hash.c:530)
0x820D475: closefrm (table.cc:1981)
0x82026F6: intern_close_table (sql_base.cc:771)
0x8209C7B: free_cache_entry (sql_base.cc:793)
0x84138D1: hash_delete (hash.c:530)
0x8202EEE: close_thread_table (sql_base.cc:1357)
0x8209CF5: close_open_tables (sql_base.cc:1166)

==16055== 1 errors in context 2 of 3:
==16055== Invalid read of size 4
0x82BEC5D: Query_cache::invalidate (sql_cache.cc:2531)
0x8234409: mysql_insert (sql_insert.cc:919)
0x81D724D: mysql_execute_command( (sql_parse.cc:2953)
0x81DB910: mysql_parse (sql_parse.cc:5645)
0x81D424D: dispatch_command(sql_parse.cc:1137)
0x81D3DD2: do_command (sql_parse.cc:794)
0x81D2300: handle_one_connection (sql_connect.cc:1115)
0x4893DA: start_thread (in /lib/libpthread-2.5.so)
0x3D606D: clone (in /lib/libc-2.5.so)

Address 0x635D260 is 280 bytes inside a block of size 996 free'd
0x400501A: free (vg_replace_malloc.c:233)
0x840DF4D: my_no_flags_free (my_malloc.c:59)
0x840E6E4: free_root (my_alloc.c:355)
0x820C8D5: free_table_share(st_table_share*) (table.cc:431)
0x8209C26: table_def_free_entry(st_table_share*) (sql_base.cc:271)
0x84138D1: hash_delete (hash.c:530)
0x820D475: closefrm(st_table*, bool) (table.cc:1981)
0x82026F6: intern_close_table(st_table*) (sql_base.cc:771)
0x8209C7B: free_cache_entry(st_table*) (sql_base.cc:793)
0x84138D1: hash_delete (hash.c:530)
0x8202EEE: close_thread_table(THD*, st_table**) (sql_base.cc:1357)
0x8209CF5: close_open_tables(THD*) (sql_base.cc:1166)

How to repeat:
...
[9 Aug 2008 19:16] Shane Bester 
some extra info so i don't forget to write a testcase :)

Attachment: bug38692_more_info.txt (text/plain), 23.06 KiB.
[9 Aug 2008 21:13] Shane Bester 
testcase.

Attachment: bug38692.c (text/plain), 7.42 KiB.
[9 Aug 2008 21:37] Shane Bester 
the testcase is nondeterministic, so let it run for at least a few hundred thousand
queries, until valgrind outputs errors.
[2 Sep 2008 16:58] Kristofer Pettersson 
progress report: The invalidation functions should probably not be executed if the query
cache isn't used.
[5 Sep 2008 14:05] Kristofer Pettersson 
* Insert_delayed::handle_inserts issues an ER_DELAYED_CANT_CHANGE_LOCK which leads to an
error. This should possibly never happen.
[10 Sep 2008 10:54] Kristofer Pettersson 
Truncate table calls 'remove_table_from_cache' which has a section specific for merge
tables:
        for (TABLE *thd_table= in_use->open_tables;
	     thd_table ;
	     thd_table= thd_table->next)
        {
          /* Do not handle locks of MERGE children. */
	  if (thd_table->db_stat && !thd_table->parent)	// If table is open
	    signalled|= mysql_lock_abort_for_thread(thd, thd_table);
        }

This causes a Delayed_insert thread to abort wait_for_lock and fail with its attempt to
upgrade to a write lock. This in turn triggered an error message which triggered a bug in
error message handling which caused an assertion in Diagnostic_area.
[10 Sep 2008 11:48] Kristofer Pettersson 
Related to http://bugs.mysql.com/bug.php?id=17436 ALTER TABLE causes pending INSERT
DELAYED updates to fail.
[10 Sep 2008 12:17] Kristofer Pettersson 
Note: It is ok for a concurrent TRUNCATE stmt to kill INSERT DELAY threads, because there
is no way to determine in advance when an delayed insert has finished anyway. This brings
us back to the original problem with how to handle error messages in a Delayed_insert
object.
[10 Sep 2008 16:52] 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/53701

2729 Kristofer Pettersson	2008-09-10
      Bug#38692 concurrent inserts cause valgrind errors in Query_cache::invalidate
            
      If a delayed insert thread was aborted by a concurrent 'truncate table'
      statement, then the diagnostic area would fail with an assert in a debug build
      because no actual error message was pushed on the stack despite a thread
      being killed.
            
      This patch adds an error message to the stack.
[16 Sep 2008 20:37] Kristofer Pettersson 
Patch for assertion failure pushed to bugteam-tree. Need to continue testing for valgrind
errors.
[26 Sep 2008 14:42] Kristofer Pettersson 
Query_cache execution path will be removed with patch for Bug#38551
[26 Sep 2008 14:43] Kristofer Pettersson 
Shane, can you try to repeat this problem using code base for current 5.1-bugteam?
[3 Oct 2008 11:23] Shane Bester 
output from the bugteam tree

Attachment: bug38692_5.0.30_tmp_mysql-5.1-bugteam_valgrind_errors.txt (text/plain), 18.99 KiB.
[6 Oct 2008 14:03] Kristofer Pettersson 
progress report:
Using an educated guess and sleep enabled me to reproduce the problem.
[6 Oct 2008 14:06] 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/55443

2730 Kristofer Pettersson	2008-10-06
      Bug#38692 concurrent inserts cause valgrind errors in Query_cache::invalidate
      
      Concurrent inserts produce valgrind error messages.
      The reason is that the query cache is invalidated after the target table object
      is closed.
      By executing query cache invalidation before the delayed insert thread is
      terminated avoids this issue.
[7 Oct 2008 11:41] 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/55555

2730 Kristofer Pettersson	2008-10-07
      Bug#38692 concurrent inserts cause valgrind errors in Query_cache::invalidate
      
      Concurrent inserts produce valgrind error messages.
      The reason is that the query cache is invalidated after the target table object
      is closed.
      
      Since the delayed insert thread already takes care of invalidating the query
      cache there is no need to try to synchronize an extra cache invalidation call.
      
      The fix is to remove the query_cache_invalidate3 call altogether.
[9 Oct 2008 20:22] Bugs System 
Pushed into 5.1.30  (revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304) (version
source revid:kpettersson@mysql.com-20080911112312-sirecjzudae3vj2n) (pib:4)
[17 Oct 2008 18:41] Bugs System 
Pushed into 6.0.8-alpha  (revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304)
(version source revid:kpettersson@mysql.com-20080915213119-3f5vwkbn3pxr1fsu) (pib:5)
[18 Oct 2008 17:15] Paul DuBois 
This was pushed into 5.1.29, not 5.1.30.
[21 Oct 2008 19:40] Paul DuBois 
Noted in 5.1.29, 6.0.8 changelogs.

A race condition between threads sometimes caused unallocated memory
to be addressed.
[28 Oct 2008 22:01] Bugs System 
Pushed into 5.1.29-ndb-6.2.17 
(revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304) (version source
revid:tomas.ulin@sun.com-20081028140209-u4emkk1xphi5tkfb) (pib:5)
[28 Oct 2008 23:20] Bugs System 
Pushed into 5.1.29-ndb-6.3.19 
(revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304) (version source
revid:tomas.ulin@sun.com-20081028194045-0353yg8cvd2c7dd1) (pib:5)
[1 Nov 2008 10:45] Bugs System 
Pushed into 5.1.29-ndb-6.4.0 
(revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304) (version source
revid:jonas@mysql.com-20081101082305-qx5a1bj0z7i8ueys) (pib:5)
[10 Nov 2008 11:51] Bugs System 
Pushed into 6.0.8-alpha  (revid:kpettersson@mysql.com-20081007094827-rkwu26j63j8bbva2)
(version source revid:horst@mysql.com-20081015193113-1bgz7kieig6c31r8) (pib:5)
[10 Nov 2008 12:36] Bugs System 
Pushed into 5.1.30  (revid:kpettersson@mysql.com-20081007094827-rkwu26j63j8bbva2) (version
source revid:horst@mysql.com-20081015192632-yaq13kdfk73t0g69) (pib:5)
[19 Jan 12:21] Bugs System 
Pushed into 5.1.31-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090119095303-uwwvxiibtr38djii)
(version source revid:tomas.ulin@sun.com-20090108105244-8opp3i85jw0uj5ib) (merge vers:
5.1.31-ndb-6.2.17) (pib:6)
[19 Jan 13:59] Bugs System 
Pushed into 5.1.31-ndb-6.3.21 (revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl)
(version source revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl) (merge vers:
5.1.31-ndb-6.3.21) (pib:6)
[19 Jan 17:05] Bugs System 
Pushed into 5.1.31-ndb-6.4.1 (revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5)
(version source revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5) (merge vers:
5.1.31-ndb-6.4.1) (pib:6)